Log window and other logging improvements

Sun, 21 Jan 2018 16:21:53 +0000

author
Tuomo Valkonen <tuomov@iki.fi>
date
Sun, 21 Jan 2018 16:21:53 +0000
changeset 34
9fce700d42de
parent 33
91421eeb4426
child 35
495a510a6d01

Log window and other logging improvements

backup.py file | annotate | diff | comparison | revisions
borgend.py file | annotate | diff | comparison | revisions
config.py file | annotate | diff | comparison | revisions
fifolog.py file | annotate | diff | comparison | revisions
instance.py file | annotate | diff | comparison | revisions
ui.py file | annotate | diff | comparison | revisions
--- a/backup.py	Sun Jan 21 14:56:56 2018 +0000
+++ b/backup.py	Sun Jan 21 16:21:53 2018 +0000
@@ -6,11 +6,12 @@
 import logging
 import time
 import keyring
+import borgend
 from instance import BorgInstance
 from queue import Queue
 from threading import Thread, Lock, Timer
 
-logger=logging.getLogger(__name__)
+logger=borgend.logger.getChild(__name__)
 
 loglevel_translation={
     'CRITICAL': logging.CRITICAL,
@@ -291,7 +292,7 @@
                 else:
                     raise NotImplementedError("Invalid operation '%s'" % op['operation'])
             except Exception as err:
-                logging.debug('Rescheduling after failure')
+                logger.debug('Rescheduling after failure')
                 self.lastrun_when=time.monotonic()
                 self.lastrun_success=False
                 self.__schedule_unlocked()
@@ -348,7 +349,7 @@
             self.timer=None
 
             if self.__is_running_unlocked():
-                logging.info('Aborted queue operation, as an operation is already running')
+                logger.info('Aborted queue operation, as an operation is already running')
             else:
                 # TODO: Queue on 'repository' and online status for SSH, etc.
 
@@ -392,8 +393,8 @@
             if op:
                 now=time.monotonic()
                 delay=max(0, op['when_monotonic']-now)
-                logging.info("Scheduling '%s' (detail: %s) of '%s' in %d seconds" %
-                             (op['operation'], op['detail'], self.name, delay))
+                logger.info("Scheduling '%s' (detail: %s) of '%s' in %d seconds" %
+                            (op['operation'], op['detail'], self.name, delay))
                 tmr=Timer(delay, self.__queue_timed_operation)
                 self.scheduled_operation=op
                 self.timer=tmr
--- a/borgend.py	Sun Jan 21 14:56:56 2018 +0000
+++ b/borgend.py	Sun Jan 21 16:21:53 2018 +0000
@@ -1,33 +1,67 @@
 #!/usr/local/bin/python3
 
 import logging
-from threading import Thread
+from fifolog import FIFOHandler
+
+#
+# Branding
+#
+appname="borgend"
+appname_stylised="Borgend"
+
+#
+# Logging configuration
+#
 
-logging.basicConfig(#filename='example.log',
-                    #format='%(levelname)s:%(message)s',
-                    level=logging.DEBUG)
+loglevel=logging.DEBUG
+logfmt="%(asctime)s:%(levelname)s:%(name)s:%(message)s"
+fifolog_capacity=1000
+fifolog_level=logging.WARNING
+fifolog_fmt="%(asctime)s:%(levelname)s:%(message)s"
 
-logger=logging.getLogger(__name__)
+#
+# Setup logger
+#
+
+logger=logging.getLogger(appname)
+logger.setLevel(loglevel)
+logger.propagate=True
+fifolog=FIFOHandler(fifolog_capacity)
+logger.addHandler(fifolog)
+fifolog.setLevel(fifolog_level)
+fifolog.setFormatter(logging.Formatter(fifolog_fmt))
 
-from backup import Backup
-from config import settings
-from queue import Queue
-from ui import BorgendTray
-import signal, os
+if __name__=="__main__":
+
+    import logging.handlers
+    import os
+    import config
+
+    if not os.path.isdir(config.logs_dir):
+        os.makedirs(config.logs_dir)
+
+    handler=logging.handlers.TimedRotatingFileHandler(
+        os.path.join(config.logs_dir, appname+'.log'),
+        when='D', interval=1)
+    handler.setFormatter(logging.Formatter(logfmt))
+    logger.addHandler(handler)
 
-backupconfigs=settings['backups']
-backups=[None]*len(backupconfigs);
+    from threading import Thread
+    from backup import Backup
+    from queue import Queue
+    from ui import BorgendTray
+    import signal, os
 
-for i in range(len(backupconfigs)):
-    logger.info('Setting up backup set %d' % i)
-    backups[i]=Backup(i, backupconfigs[i])
-    backups[i].schedule()
+    backupconfigs=config.settings['backups']
+    backups=[None]*len(backupconfigs);
 
-if __name__ == "__main__":
-    #print(settings)
+    for i in range(len(backupconfigs)):
+        logger.info('Setting up backup set %d' % i)
+        backups[i]=Backup(i, backupconfigs[i])
+        backups[i].schedule()
+
     tray=BorgendTray(backups);
     tray.run()
-    pass
 
     #
     # This shit is fucked, disables ^C etc., and threading doesn't seem to help
--- a/config.py	Sun Jan 21 14:56:56 2018 +0000
+++ b/config.py	Sun Jan 21 16:21:53 2018 +0000
@@ -8,9 +8,10 @@
 import os
 import string
 import logging
+import borgend
 from functools import reduce
 
-logger=logging.getLogger(__name__)
+logger=borgend.logger.getChild(__name__)
 
 #
 # Defaults
@@ -37,25 +38,18 @@
 }
 
 #
-# Branding
-#
-
-appname="borgend"
-appname_stylised="Borgend"
-
-#
 # Locations
 #
 
 if False:
     import xdg
-    cfgfile=os.path.join(xdg.XDG_CONFIG_HOME, appname, "config.yaml")
-    logs_location=os.path.join(xdg.XDG_DATA_HOME, appname, "logs")
+    cfgfile=os.path.join(xdg.XDG_CONFIG_HOME, borgend.appname, "config.yaml")
+    logs_dir=os.path.join(xdg.XDG_DATA_HOME, borgend.appname, "logs")
 else:
     import rumps
-    __base=rumps.application_support(appname)
+    __base=rumps.application_support(borgend.appname)
     cfgfile=os.path.join(__base, "config.yaml")
-    logs_location=os.path.join(__base, "logs")
+    logs_dir=os.path.join(__base, "logs")
 
 #
 # Type checking etc.
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/fifolog.py	Sun Jan 21 16:21:53 2018 +0000
@@ -0,0 +1,18 @@
+#
+# FIFO memory logger
+#
+
+from logging.handlers import BufferingHandler
+
+class FIFOHandler(BufferingHandler):
+    def shouldFlush(self, record):
+        return False
+
+    def emit(self, record):
+        self.buffer.append(record)
+        l=len(self.buffer)
+        if l>self.capacity:
+            self.buffer=self.buffer[(l-self.capacity+1):l]
+
+    def formatAll(self):
+        return [self.format(record) for record in self.buffer]
--- a/instance.py	Sun Jan 21 14:56:56 2018 +0000
+++ b/instance.py	Sun Jan 21 16:21:53 2018 +0000
@@ -5,10 +5,11 @@
 import json
 import logging
 import os
+import borgend
 from subprocess import Popen, PIPE
 from config import settings, arglistify
 
-logger=logging.getLogger(__name__)
+logger=borgend.logger.getChild(__name__)
 
 necessary_opts=['--log-json', '--progress']
 
--- a/ui.py	Sun Jan 21 14:56:56 2018 +0000
+++ b/ui.py	Sun Jan 21 16:21:53 2018 +0000
@@ -6,11 +6,12 @@
 import time
 import datetime
 import logging
+import borgend
 from threading import Lock, Timer
-from config import settings, appname_stylised
+from config import settings
 import objc
 
-logger=logging.getLogger(__name__)
+logger=borgend.logger.getChild(__name__)
 
 INACTIVE=0
 ACTIVE=1
@@ -33,10 +34,13 @@
 # Workaround to rumps brokenness;
 # see https://github.com/jaredks/rumps/issues/59
 def notification_workaround(title, subtitle, message):
-    NSDictionary = objc.lookUpClass("NSDictionary")
-    d=NSDictionary()
+    try:
+        NSDictionary = objc.lookUpClass("NSDictionary")
+        d=NSDictionary()
 
-    rumps.notification(title, subtitle, message, data=d)
+        rumps.notification(title, subtitle, message, data=d)
+    except Exception as err:
+        logger.debug('Unable to display notificaton:%s:%s',err.__class__.__name__, str(err))
 
 # Based on code snatched from
 # https://stackoverflow.com/questions/12523586/python-format-size-application-converting-b-to-kb-mb-gb-tb/37423778
@@ -104,7 +108,6 @@
 
     return title, state
 
-
 class BorgendTray(rumps.App):
     def __init__(self, backups):
         self.lock=Lock()
@@ -130,6 +133,7 @@
             menu, state=self.__rebuild_menu()
 
             self.refresh_timer=None
+            self.logwindow=None
 
             super().__init__(traynames[state], menu=menu, quit_button=None)
 
@@ -147,6 +151,9 @@
             menu.append(item)
             state=combine_state(state, this_state)
 
+        menu_log=rumps.MenuItem("Show log", callback=self.showlog)
+        menu.append(menu_log)
+
         if not settings['no_quit_menu_entry']:
             menu_quit=rumps.MenuItem("Quit...", callback=self.my_quit)
             menu.append(menu_quit)
@@ -180,10 +187,11 @@
             logger.debug("Opening notification for error %s '%s'",
                          msgid, errorlog['message'])
 
-            notification_workaround(appname_stylised,
+            notification_workaround(borgend.appname_stylised,
                                     msgid, errorlog['message'])
 
     def my_quit(self, _):
+        logging.shutdown()
         rumps.quit_application()
 
     def __menu_select_backup(self, sender, b):
@@ -194,10 +202,25 @@
         except Exception as err:
             logger.debug("Opening notification for exception %s '%s'",
                          err.__class__.__name__, str(err))
-            notification_workaround(appname_stylised,
+            notification_workaround(borgend.appname_stylised,
                                     err.__class__.__name__, str(err))
 
     @rumps.notifications
     def notification_center(data):
         pass
 
+    def showlog(self, _):
+        try:
+            if not self.logwindow:
+                lines=borgend.fifolog.formatAll()
+                msg="\n".join(lines[0:])
+                self.logwindow=rumps.Window(title=borgend.appname_stylised+' log',
+                                            default_text=msg,
+                                            ok='Close',
+                                            dimensions=(640,320))
+                self.logwindow.run()
+                # Does not return until closed
+                self.logwindow=None
+        except Exception as err:
+            logger.critical('%s:%s', err.__class__.__name__, str(err))
+

mercurial