sezanzeb#197 timeouts, service Requires, added key-mapper-control deb…

…ug log file

bin/key-mapper-control

@@ -28,7 +28,7 @@ import sys
 import argparse
 import logging
 
-from keymapper.logger import logger, update_verbosity, log_info
+from keymapper.logger import logger, update_verbosity, log_info, add_filehandler
 from keymapper.config import config
 
 # import keymapper modules as late as possible to make sure the correct
@@ -133,11 +133,13 @@ def communicate(options, daemon):
         # if device was specified, autoload for that one. if None autoload
         # for all devices.
         if options.device is None:
+            logger.info('Autoloading all')
             # timeout is not documented, for more info see
             # https://github.com/LEW21/pydbus/blob/master/pydbus/proxy_method.py
             daemon.autoload(timeout=10)
         else:
             group = require_group()
+            logger.info('Autoloading %s', options.device)
             daemon.autoload_single(group.key, timeout=2)
 
     if options.command == START:
@@ -234,7 +236,9 @@ if __name__ == '__main__':
         log_info()
         sys.exit(0)
 
-    update_verbosity(options.debug)
+    if options.debug:
+        add_filehandler('/var/log/key-mapper-control')
+        update_verbosity(True)
 
     logger.debug('Call for "%s"', sys.argv)
 

data/99-key-mapper.rules

@@ -2,6 +2,7 @@
 #   udevadm monitor --property
 #   udevadm info --query=all --name=/dev/input/event3
 # to test changes:
+#   sudo udevadm control --log-priority=debug
 #   sudo udevadm control --reload-rules
 #   journalctl -f
-ACTION=="add", SUBSYSTEM=="input", RUN+="/bin/key-mapper-control --command autoload --device $env{DEVNAME}"
+ACTION=="add", SUBSYSTEM=="input", RUN+="/bin/key-mapper-control --command autoload --device $env{DEVNAME} -d"

data/key-mapper.service

@@ -1,5 +1,8 @@
 [Unit]
 Description=Service to inject keycodes without the GUI application
+# dbus is required for ipc between gui and key-mapper-control
+Requires=dbus.service
+After=dbus.service
 
 [Service]
 Type=dbus

keymapper/daemon.py

@@ -47,6 +47,9 @@
 
 
 BUS_NAME = "keymapper.Control"
+# timeout in seconds, see
+# https://github.com/LEW21/pydbus/blob/cc407c8b1d25b7e28a6d661a29f9e661b1c9b964/pydbus/proxy.py
+BUS_TIMEOUT = 10
 
 
 class AutoloadHistory:
@@ -183,7 +186,7 @@ def connect(cls, fallback=True):
         """
         try:
             bus = SystemBus()
-            interface = bus.get(BUS_NAME)
+            interface = bus.get(BUS_NAME, timeout=BUS_TIMEOUT)
             logger.info("Connected to the service")
         except GLib.GError as error:
             if not fallback:
@@ -208,7 +211,7 @@ def connect(cls, fallback=True):
             # try a few times if the service was just started
             for attempt in range(3):
                 try:
-                    interface = bus.get(BUS_NAME)
+                    interface = bus.get(BUS_NAME, timeout=BUS_TIMEOUT)
                     break
                 except GLib.GError as error:
                     logger.debug(
@@ -221,9 +224,10 @@ def connect(cls, fallback=True):
                 logger.error("Failed to connect to the service")
                 sys.exit(1)
 
-        config_path = get_config_path()
-        logger.debug('Telling service about "%s"', config_path)
-        interface.set_config_dir(get_config_path())
+        if USER != "root":
+            config_path = get_config_path()
+            logger.debug('Telling service about "%s"', config_path)
+            interface.set_config_dir(get_config_path())
 
         return interface
 

keymapper/logger.py

@@ -27,6 +27,7 @@
 import time
 import logging
 import pkg_resources
+from datetime import datetime
 
 from keymapper.user import HOME
 
@@ -194,28 +195,37 @@ def update_verbosity(debug):
             # since this is optional, just skip all exceptions
             if not isinstance(error, ImportError):
                 logger.debug("Cannot use rich.traceback: %s", error)
+
+        logger.debug("Started debug logs at: %s", str(datetime.now()))
     else:
         logger.setLevel(logging.INFO)
 
 
 def add_filehandler(log_path=LOG_PATH):
     """Clear the existing logfile and start logging to it."""
-    logger.info('This output is also stored in "%s"', LOG_PATH)
-
-    log_path = os.path.expanduser(log_path)
-    os.makedirs(os.path.dirname(log_path), exist_ok=True)
+    try:
+        log_path = os.path.expanduser(log_path)
+        os.makedirs(os.path.dirname(log_path), exist_ok=True)
 
-    if os.path.exists(log_path):
-        # keep the log path small, start from scratch each time
         if os.path.isdir(log_path):
             # used to be a folder < 0.8.0
             shutil.rmtree(log_path)
-        else:
-            os.remove(log_path)
 
-    file_handler = logging.FileHandler(log_path)
-    file_handler.setFormatter(Formatter())
+        if os.path.exists(log_path):
+            # the logfile should not be longer than 1000 lines to avoid overflowing
+            # the storage
+            with open(log_path, "r") as file:
+                content = file.readlines()[-200:] + ["---\n"]
+
+            with open(log_path, "w") as file:
+                file.truncate(0)
+                file.writelines(content)
+
+        file_handler = logging.FileHandler(log_path)
+        file_handler.setFormatter(Formatter())
 
-    logger.info('Logging to "%s"', log_path)
+        logger.info('Logging to "%s"', log_path)
 
-    logger.addHandler(file_handler)
+        logger.addHandler(file_handler)
+    except PermissionError:
+        logger.debug('No permission to log to "%s"', log_path)

tests/testcases/test_daemon.py

@@ -137,7 +137,7 @@ def set_config_dir(self, *args, **kwargs):
                 nonlocal set_config_dir_callcount
                 set_config_dir_callcount += 1
 
-        type(SystemBus()).get = lambda *args: FakeConnection()
+        type(SystemBus()).get = lambda *args, **kwargs: FakeConnection()
         self.assertIsInstance(Daemon.connect(), FakeConnection)
         self.assertEqual(set_config_dir_callcount, 1)
 

tests/testcases/test_logger.py

@@ -75,11 +75,17 @@ def test_clears_log(self):
         path = os.path.join(tmp, "logger-test")
         os.makedirs(os.path.dirname(path), exist_ok=True)
         os.mknod(path)
+
         with open(path, "w") as f:
-            f.write("foo")
+            f.write("line\n" * 1000 + "end")
+
         add_filehandler(os.path.join(tmp, "logger-test"))
         with open(path, "r") as f:
-            self.assertEqual(f.read(), "")
+            # it only keeps the newest information
+            content = f.readlines()
+            self.assertLess(len(content), 500)
+            self.assertEqual(content[-1], "end---\n")
+            # after "---" new log will appear
 
     def test_debug(self):
         path = os.path.join(tmp, "logger-test")