Merge branch 'master' into docker-fix

backend/api/core.py

@@ -2,20 +2,22 @@
 Module init.
 Contains function for starting up the flask process
 """
-import logging
-
 from api.routes import RouteManager
 from api.server import WaitressAPIServer
 from api.app import FlaskApp
 from microlab.interface import MicrolabInterface
+from util.logger import MultiprocessingLogger
+
 
+def run_flask(in_queue, out_queue, logging_queue):
 
-def run_flask(in_queue, out_queue):
+    # The initialize_logger call only needs to happen once when a new process is started.
+    # Logs from this point on will just require a call to MultiprocessingLogger.get_logger(<logger_name>)
+    # within the same process.
+    MultiprocessingLogger.initialize_logger(logging_queue)
 
-    logging.info("### STARTING API ###")
-    werkzeugLogger = logging.getLogger("werkzeug")
-    # suppresses logging of individual requests to endpoints. Prevents log spam
-    werkzeugLogger.setLevel(logging.WARNING)
+    logger = MultiprocessingLogger.get_logger(__name__)
+    logger.info("### STARTING API ###")
 
     microlab_interface = MicrolabInterface(in_queue, out_queue)
 

backend/api/server.py

@@ -7,27 +7,34 @@
 
 from config import microlabConfig as config
 from microlab.interface import MicrolabInterface
-
-
-LOGGER = logging.getLogger(__name__)
+from util.logger import MultiprocessingLogger
 
 
 class WaitressAPIServer:
 
     _server = None
     _microlab_interface = None
 
+    _logger = None
+
     def __init__(self, app: Flask):
         self._app = app
         signal.signal(signal.SIGINT, self._shutdown_signal_handler)
         signal.signal(signal.SIGTERM, self._shutdown_signal_handler)
 
+        if self._logger is None:
+            self._logger = self._get_logger()
+
+    @classmethod
+    def _get_logger(cls) -> logging.Logger:
+        return MultiprocessingLogger.get_logger(__name__)
+
     @classmethod
     def set_microlab_interface(cls, microlab_interface: MicrolabInterface):
         cls._microlab_interface = microlab_interface
 
     def run(self):
-        LOGGER.info('Starting backend waitress server')
+        self._logger.info('Starting backend waitress server')
         self._get_server(self._app).run()
 
     def _shutdown_signal_handler(self, signum, frame):
@@ -42,10 +49,13 @@ def _get_server(cls, app: Flask):
 
     @classmethod
     def shutdown(cls):
+        if cls._logger is None:
+            cls._logger = cls._get_logger()
+
         if cls._server:
-            LOGGER.debug('Shutting down waitress server')
+            cls._logger.debug('Shutting down waitress server')
             cls._server.close()
-            LOGGER.debug('Completed shut down of waitress server')
+            cls._logger.debug('Completed shut down of waitress server')
 
         cls._microlab_interface.close_to_microlab_queue()
 

backend/config.py

@@ -19,24 +19,26 @@ class to abstract away setters to write to disk, and ability to reload
     changes from disk.
     """
     def __init__(self):
-        vdt = Validator()
+        config_file_name = '/etc/microlab/microlab.ini'
 
-        configFileName = '/etc/microlab/microlab.ini'
+        makedirs(path.dirname(config_file_name), exist_ok=True)
 
-        makedirs(path.dirname(configFileName), exist_ok=True)
+        self.config = ConfigObj(config_file_name, configspec="defaultconfig.ini")
 
-        self.config = ConfigObj(configFileName, configspec="defaultconfig.ini")
+    def validate_config(self):
 
-        res = self.config.validate(vdt, copy=True, preserve_errors=True)
+        validator = Validator()
+
+        validation_data = self.config.validate(validator, copy=True, preserve_errors=True)
 
         self.config.write()
 
-        for entry in flatten_errors(self.config, res):
+        for entry in flatten_errors(self.config, validation_data):
             section_list, key, error = entry
-            partialKey = self.config
+            partial_key = self.config
             for section in section_list:
-                partialKey = partialKey[section]
-                default = partialKey.restore_default(key)
+                partial_key = partial_key[section]
+                default = partial_key.restore_default(key)
 
                 if key is not None:
                     section_list.append(key)

backend/hardware/core.py

@@ -7,11 +7,12 @@
 file.
 """
 
+import logging
 import time
 import config
 from hardware import devicelist
 from enum import Enum
-import logging
+from util.logger import MultiprocessingLogger
 
 from hardware.devicelist import loadHardwareConfiguration
 
@@ -25,11 +26,13 @@ class MicroLabHardwareState(Enum):
 class MicroLabHardware:
 
     _microlabHardware = None
+    _logger = None
 
     def __init__(self, deviceDefinition: list[dict]):
         """
         Constructor. Initializes the hardware.
         """
+
         self.startTime = None
         self.devices = {}
         self.state = MicroLabHardwareState.STARTING
@@ -38,12 +41,22 @@ def __init__(self, deviceDefinition: list[dict]):
         self.startTime = time.monotonic()
         self.loadHardware(deviceDefinition)
 
+        if self._logger is None:
+            self._logger = self._get_logger()
+
+    @classmethod
+    def _get_logger(cls) -> logging.Logger:
+        return MultiprocessingLogger.get_logger(__name__)
+
     @classmethod
     def get_microlab_hardware_controller(cls):
+        if cls._logger is None:
+            cls._logger = cls._get_logger()
+
         if not cls._microlabHardware:
-            logging.info("")
-            logging.info("### STARTING MICROLAB HARDWARE CONTROLLER ###")
-            logging.info("Loading microlab hardware configuration.")
+            cls._logger.info("")
+            cls._logger.info("### STARTING MICROLAB HARDWARE CONTROLLER ###")
+            cls._logger.info("Loading microlab hardware configuration.")
 
             hardwareConfig = loadHardwareConfiguration()
             deviceDefinitions = hardwareConfig['devices']
@@ -67,7 +80,7 @@ def loadHardware(self, deviceDefinition: list[dict]):
             self.state = MicroLabHardwareState.INITIALIZED
             return True, ''
         except Exception as e:
-            logging.exception(str(e))
+            self._logger.exception(str(e))
             self.state = MicroLabHardwareState.FAILED_TO_START
             self.error = e
             return False, str(e)

backend/hardware/devicelist.py

@@ -7,9 +7,9 @@
 from config import microlabConfig as config
 import yaml
 from os.path import exists
-import logging
 from functools import cmp_to_key
 from copy import copy
+from util.logger import MultiprocessingLogger
 
 
 def sort_device_configs(deviceConfigs: list[dict]):
@@ -48,12 +48,13 @@ def loadHardwareConfiguration() -> dict:
 
 def setupDevices(deviceDefinitions: list[dict]):
     validateConfiguration(deviceDefinitions)
+    logger = MultiprocessingLogger.get_logger(__name__)
 
     devices = {}
 
     for device in deviceDefinitions:
-        logging.info('Loading device "{0}".'.format(device['id']))
-        logging.debug('{0} configuration: {1}'.format(device['id'], device))
+        logger.info('Loading device "{0}".'.format(device['id']))
+        logger.debug('{0} configuration: {1}'.format(device['id'], device))
         deviceType = device["type"]
         deviceID = device['id']
         if deviceType == "tempController":
@@ -70,7 +71,7 @@ def setupDevices(deviceDefinitions: list[dict]):
             devices[deviceID] = grbl.createGRBL(device, devices)
         else:
             raise Exception("Unsupported device type '{0}'".format(deviceType))
-        logging.info('"{0}" loaded successfully.'.format(device['id']))
+        logger.info('"{0}" loaded successfully.'.format(device['id']))
     return devices
 
 

backend/hardware/gpiochip/gpiod.py

@@ -1,6 +1,6 @@
 from hardware.gpiochip.base import GPIOChip, LINE_REQ_DIR_OUT
 import gpiod
-import logging
+from util.logger import MultiprocessingLogger
 
 
 class GPIODChip(GPIOChip):
@@ -15,6 +15,8 @@ def __init__(self, gpio_config: dict):
               dictionary mapping strings to line numbers
               for adding human readable names to GPIO lines
         """
+        self._logger = MultiprocessingLogger.get_logger(__name__)
+
         self.output_offsets = []
         self.output_values = []
         self.output_lines = []
@@ -24,7 +26,7 @@ def __init__(self, gpio_config: dict):
         if 'lineAliases' in gpio_config:
             for alias, line in gpio_config['lineAliases'].items():
                 self.lineAliases[alias] = line
-        logging.debug(self.lineAliases)
+        self._logger.debug(self.lineAliases)
 
     def __output(self):
         """

backend/hardware/gpiochip/gpiod_chipset.py

@@ -1,5 +1,5 @@
 from hardware.gpiochip.base import GPIOChip, LINE_REQ_DIR_OUT
-import logging
+from util.logger import MultiprocessingLogger
 
 
 class GPIODChipset(GPIOChip):
@@ -14,6 +14,8 @@ def __init__(self, gpio_config: dict, devices: dict):
               dictionary mapping strings to line numbers
               for adding human readable names to GPIO lines
         """
+        self._logger = MultiprocessingLogger.get_logger(__name__)
+
         self.chips = {
             "defaultChip": devices[gpio_config["defaultChipID"]],
         }
@@ -25,10 +27,10 @@ def __init__(self, gpio_config: dict, devices: dict):
         for chipID, chip in self.chips.items(): 
             for alias, line in chip.lineAliases.items():
                 if alias in self.lineAliases:
-                    logging.warning("GPIO line alias '{0}' has a conflict between chips {1} and {2}. Using {2}.".format(alias, chipID, self.lineAliases[alias]))
+                    self._logger.warning("GPIO line alias '{0}' has a conflict between chips {1} and {2}. Using {2}.".format(alias, chipID, self.lineAliases[alias]))
                     continue
             self.lineAliases[alias] = chipID
-        logging.debug(self.lineAliases)
+        self._logger.debug(self.lineAliases)
 
     def setup(self, pin, pinType=LINE_REQ_DIR_OUT, outputValue=0):
         """

backend/hardware/gpiochip/gpiod_simulation.py

@@ -1,5 +1,5 @@
 from hardware.gpiochip.base import LINE_REQ_DIR_OUT
-import logging
+from util.logger import MultiprocessingLogger
 
 
 class GPIODChipSimulation():
@@ -14,6 +14,8 @@ def __init__(self, gpio_config: dict):
               dictionary mapping strings to line numbers
               for adding human readable names to GPIO lines
         """
+        self._logger = MultiprocessingLogger.get_logger(__name__)
+
         self.output_offsets = []
         self.output_values = []
         self.output_lines = []
@@ -22,7 +24,7 @@ def __init__(self, gpio_config: dict):
         if 'lineAliases' in gpio_config:
             for alias, line in gpio_config['lineAliases'].items():
                 self.lineAliases[alias] = line
-        logging.debug(self.lineAliases)
+        self._logger.debug(self.lineAliases)
 
     def __output(self):
         """

backend/hardware/gpiochip/grbl.py

@@ -1,5 +1,5 @@
 from hardware.gpiochip.base import GPIOChip, LINE_REQ_DIR_OUT
-import logging
+from util.logger import MultiprocessingLogger
 
 class GRBLChip(GPIOChip):
     def __init__(self, gpio_config: dict, devices: dict):
@@ -13,14 +13,16 @@ def __init__(self, gpio_config: dict, devices: dict):
               dictionary mapping strings to pin numbers
               for adding human readable names to GPIO pins
         """
+        self._logger = MultiprocessingLogger.get_logger(__name__)
+
         self.grbl = devices[gpio_config["grblID"]]
         self.output_offsets = []
         self.output_values = []
         self.pinAliases = {}
         if 'lineAliases' in gpio_config:
             for alias, pin in gpio_config['lineAliases'].items():
                 self.pinAliases[alias] = pin
-        logging.debug(self.pinAliases)
+        self._logger.debug(self.pinAliases)
 
     def __output(self):
         """

backend/hardware/grbl/serial.py

@@ -1,6 +1,6 @@
 from hardware.grbl.base import GRBL
 import serial
-import logging
+from util.logger import MultiprocessingLogger
 
 class GRBLSerial(GRBL):
     def __init__(self, grbl_config: dict):
@@ -11,6 +11,8 @@ def __init__(self, grbl_config: dict):
             grblPort
                 string - Serial device for communication with grbl
         """
+        self._logger = MultiprocessingLogger.get_logger(__name__)
+
         self.grblSer = serial.Serial(grbl_config["grblPort"], 115200, timeout=1)
 
     def grblWrite(self, command: str, retries=3):
@@ -22,7 +24,7 @@ def grblWrite(self, command: str, retries=3):
         response = self.grblSer.read_until()
         if "error" in str(response):
             if retries > 0:
-                logging.warning("grbl error: {0} for command: {1}, retrying"
+                self._logger.warning("grbl error: {0} for command: {1}, retrying"
                                 .format(response, command))
                 self.grblWrite(command, retries - 1)
             else:

backend/hardware/reagentdispenser/peristalticpump.py

@@ -1,6 +1,5 @@
 from hardware.reagentdispenser.base import ReagentDispenser
-import logging
-
+from util.logger import MultiprocessingLogger
 
 class PeristalticPump(ReagentDispenser):
     def __init__(self, reagent_dispenser_config: dict, devices: dict):
@@ -20,6 +19,7 @@ def __init__(self, reagent_dispenser_config: dict, devices: dict):
                 Z
                     mmPerml   Arbitrary scaling factor
         """
+        self._logger = MultiprocessingLogger.get_logger(__name__)
         self.grbl = devices[reagent_dispenser_config["grblID"]]
         self.peristalticPumpsConfig = reagent_dispenser_config["peristalticPumpsConfig"]
         self.grbl.grblWrite("G91")
@@ -43,11 +43,11 @@ def dispense(self, pumpId, volume, duration=None):
         if duration:
             dispenseSpeed = min((volume / duration) * 60 * mmPerml, dispenseSpeed)
         command = "G91 G1 {0}{1} F{2}".format(pumpId, totalmm, dispenseSpeed)
-        logging.debug("Dispensing with command '{}'".format(command))
+        self._logger.debug("Dispensing with command '{}'".format(command))
         self.grbl.grblWrite(command)
 
         dispenseTime = abs(totalmm) / (dispenseSpeed / 60)
-        logging.info(
+        self._logger.info(
             "Dispensing {}ml with motor speed of {}mm/min over {} seconds".format(
                 volume, dispenseSpeed, dispenseTime
             )