From 38722561afeeba1269a7915b9726bc050577a214 Mon Sep 17 00:00:00 2001
From: Marko Mecina <marko.mecina@univie.ac.at>
Date: Thu, 25 Aug 2022 14:10:27 +0200
Subject: [PATCH] improve robustness of log_server

---
 Ccs/DBus_Basic.py | 27 ++++++++-------
 Ccs/log_server.py | 88 ++++++++++++++++++++++-------------------------
 2 files changed, 57 insertions(+), 58 deletions(-)

diff --git a/Ccs/DBus_Basic.py b/Ccs/DBus_Basic.py
index d0b6051..9be63bb 100644
--- a/Ccs/DBus_Basic.py
+++ b/Ccs/DBus_Basic.py
@@ -1,11 +1,15 @@
 # This file is used to set up a D-Bus
 import dbus
 import dbus.service
-import ccs_function_lib as cfl
 import os
 
+import log_server
 
-# Set up two Methodes to excess over a given dbus name
+# STDOUT = '/dev/null'
+STDOUT = '/tmp/log_server.log'
+
+
+# Set up methods to access via a given dbus name
 class MessageListener(dbus.service.Object):
     def __init__(self, win, Bus_Name, *args):
         project = None
@@ -22,7 +26,7 @@ class MessageListener(dbus.service.Object):
         # Check if the Bus name already exists and increase the number if it does
         counting = 1
         check = True
-        while check == True:
+        while check:
             counting += 1
             for service in dbus.SessionBus().list_names():
                 if service == Bus_Name:
@@ -37,9 +41,10 @@ class MessageListener(dbus.service.Object):
         self.name = dbus.service.BusName(self.Bus_Name, bus=self.bus)
         super().__init__(self.name, '/MessageListener')
         self.win = win
-        #### This will be a series of functions to let the user use more than one 'instance' of the CCS running on the
+
+        # This will be a series of functions to let the user use more than one 'instance' of the CCS running on the
         # same machine,
-        # Variabel project is the name of the group of application working together
+        # Variable project is the name of the group of applications working together
         if not project:
             project = self.win.cfg['ccs-database']['project']
 
@@ -48,18 +53,16 @@ class MessageListener(dbus.service.Object):
         # This exception is necessary for the Poolmanager since most of the time a GUI does not exist
         try:
             self.win.set_title(str(project) + ': ' + str(self.win.get_title()) + ' ' + str(counting - 1))
-        except:
-            # Looks like a odd title name but is reshaped in pus_datapool.py
+        except Exception as err:
+            print(err)
+            # Looks like an odd title name but is reshaped in pus_datapool.py
             self.win.windowname = str(project) + ': @ ' + str(counting - 1)
-        ###
 
         # Tell the terminal that a bus has been set up, this function has to exist in every file
         self.win.connect_to_all(Bus_Name, counting - 1)
 
         # Start the Logging TCP-Server, the check if it is already setup is in log_server.py
-        import log_server
-        log_server_path = log_server.__file__
-        os.system('nohup python3 ' + str(log_server_path) + ' >/dev/null 2>&1 &')
+        os.system('nohup python3 {} >{} 2>&1 &'.format(log_server.__file__, STDOUT))
         # subprocess.Popen(['python3', log_server_path])
 
     # Return all available methods
@@ -70,7 +73,7 @@ class MessageListener(dbus.service.Object):
         for method in method_list_former:
             if method.startswith('__'):
                 pass
-            elif argument and not argument in method:
+            elif argument and argument not in method:
                 pass
             else:
                 method_list.append(method)
diff --git a/Ccs/log_server.py b/Ccs/log_server.py
index 4adcd79..1d71757 100644
--- a/Ccs/log_server.py
+++ b/Ccs/log_server.py
@@ -2,16 +2,21 @@ import pickle
 import logging
 import logging.handlers
 import socketserver
-import struct
 import datetime
 import dbus
 import dbus.service
 import time
+import select
 import os
 from os import listdir
 from os.path import isfile, join
 
 import confignator
+cfg = confignator.get_config()
+
+SOCKET_TIMEOUT = 0.5
+SOCKET_RD_INTERVAL = 0.5
+LOGFMT = '%(asctime)s: %(name)-15s %(levelname)-8s %(message)s'
 
 
 class LogRecordStreamHandler(socketserver.StreamRequestHandler):
@@ -30,17 +35,14 @@ class LogRecordStreamHandler(socketserver.StreamRequestHandler):
             chunk = self.connection.recv(4)
             if len(chunk) < 4:
                 break
-            slen = struct.unpack('>L', chunk)[0]
+            slen = int.from_bytes(chunk, 'big')
             chunk = self.connection.recv(slen)
             while len(chunk) < slen:
                 chunk = chunk + self.connection.recv(slen - len(chunk))
-            obj = self.unPickle(chunk)
+            obj = pickle.loads(chunk)
             record = logging.makeLogRecord(obj)
             self.handleLogRecord(record)
 
-    def unPickle(self, data):
-        return pickle.loads(data)
-
     def handleLogRecord(self, record):
         # if a name is specified, we use the named logger rather than the one
         # implied by the record.
@@ -65,57 +67,40 @@ class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):
     def __init__(self, host='localhost',
                  port=logging.handlers.DEFAULT_TCP_LOGGING_PORT, handler=LogRecordStreamHandler):
 
-        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)
-        self.abort = 0
-        self.timeout = 1
+        super(LogRecordSocketReceiver, self).__init__((host, port), handler)
+
+        # socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)
+        # self.abort = 0
+        self.timeout = SOCKET_TIMEOUT
         self.logname = None
 
     def serve_until_stopped(self, cfg):
 
-        import select
-
         # Check all dbus connections if any process is running, if not close the logging file
-        dbustype = dbus.SessionBus()
         while True:
-            dbus_names = cfg['ccs-dbus_names']
             closing = True
+            dbus_names = cfg['ccs-dbus_names'].values()
 
-            our_con = []
             for service in dbus.SessionBus().list_names():
-                if service.startswith('com'):
-                    our_con.append(service)
-
-            for app in our_con:
-                if app[:-1] in cfg['ccs-dbus_names'].values():
+                if service.startswith('com') and service[:-1] in dbus_names:
                     closing = False
 
-            #for name in dbus_names:
-            #    Bus_name = cfg.get('ccs-dbus_names', name)
-            #    try:
-            #        connection = dbustype.get_object(Bus_name, '/MessageListener')
-            #        connection.LoggingCheck()
-            #    except:
-            #        closing += 1
-
-            # If anything is incomming call the handler and log it
-            rd, wr, ex = select.select([self.socket.fileno()],
-                                       [], [],
-                                       self.timeout)
+            # If anything is incoming call the handler and log it
+            rd, wr, ex = select.select([self.socket.fileno()], [], [], self.timeout)
             if rd:
                 self.handle_request()
-            abort = self.abort
 
         # Close the file if there is no more dbus connection
             if closing:
                 break
             else:
-                time.sleep(.1)
+                time.sleep(SOCKET_RD_INTERVAL)
 
 
 def main():
     # Specify how the format of the Log-Filename is and where to save it
     logname = '%Y%m%d_%H%M%S'
-    logpath = confignator.get_option('ccs-paths', 'log-file-dir')
+    logpath = cfg.get('ccs-paths', 'log-file-dir')
 
     # Choose which time should be used for the title
     tnow = datetime.datetime.now          # Use the local- Time for the log file title
@@ -124,18 +109,28 @@ def main():
     # Get the time in the correct format
     logtimestart = datetime.datetime.strftime(tnow(), logname)
     logfilename = os.path.join(logpath, logtimestart + '.log')
+    logfmt = LOGFMT
 
-    # Connect to the config file
-    cfg = confignator.get_config(file_path=confignator.get_option('config-files', 'ccs'))
+    logger = logging.getLogger('log_server')
 
     # Start the server
     # If it is already running LogRecordSocketReciever() will give an error and the server is therefor not started again
     try:
         tcpserver = LogRecordSocketReceiver()
 
+        # set up the file logging
+        # logging.basicConfig(format='%(asctime)s: %(name)-15s %(levelname)-8s %(message)s', filename=logfilename)
+        fh = logging.FileHandler(filename=logfilename)
+        fh.setFormatter(logging.Formatter(logfmt))
+        rl = logging.getLogger()
+        rl.addHandler(fh)
+        rl.setLevel(getattr(logging, cfg.get('ccs-logging', 'level').upper()))
+        # rl.setLevel(logging.INFO)
+
         # Check how many log files should be kept and delete the rest
         amount = cfg.get('ccs-logging', 'max_logs')
-        if amount: # If amount is empty keep an endless amount of logs
+        # If amount is empty keep an endless amount of logs
+        if amount:
             while True:
                 onlyfiles = [f for f in listdir("logs/") if isfile(join("logs/", f))]
                 onlyfiles.sort()
@@ -144,20 +139,21 @@ def main():
                 else:
                     break
 
-        # Give a format and filename configuration for logging
-        logging.basicConfig(
-            format='%(asctime)s: %(name)-15s %(levelname)-8s %(message)s', filename=logfilename)
-        # print('TCP-server for logging is started')
+        logger.info('TCP-server for logging started')
         tcpserver.serve_until_stopped(cfg)
-    except:
-        pass
+        logger.info('TCP-server for logging shutting down')
+    # Catch exception if log_server is already running and address/port is already in use
+    except OSError:
+        logger.info('TCP-server for logging seems to be already running.')
+    except Exception as err:
+        raise err
 
 
-class Logging():
+class Logging:
     # This sets up a logging client for the already running TCP-logging Server,
-    # The logger is returned with the given name an can be used like a normal logger
+    # The logger is returned with the given name and can be used like a normal logger
     def start_logging(self, name):
-        loglevel = confignator.get_option('logging', 'level')
+        loglevel = confignator.get_option('ccs-logging', 'level')
 
         rootLogger = logging.getLogger('')
         rootLogger.setLevel(loglevel)
-- 
GitLab