device_server: pass options to DeviceServer to enable logging (#180)

When the multiprocessing start method is not fork (Windows only has
spawn, and macOS defaults to spawn), then configuration done in the
main process is not copied to the child process, i.e., the actual
device process.  This means that the logging level set on the main
process is not inherited by the DeviceServer process.

This commit passes the device server options to the DeviceServer so
that it can redo the required logging configuration on the new
process.  It does this by passing all options since we expect to
expand those.

This commit also adds dependency on the dataclasses module which means
being dependent on Python 3.7 (which is now almost 3 years old).

Author: carandraug

NEWS.rst

@@ -4,6 +4,12 @@ python-microscope releases.
 Version 0.7.0 (upcoming)
 ------------------------
 
+* The device server logging was broken in version 0.6.0 for Windows
+  and macOS (systems not using fork for multiprocessing).  This
+  version fixes that issue.
+
+* Microscope is now dependent on Python 3.7 or later.
+
 
 Version 0.6.0 (2021/01/14)
 --------------------------

microscope/device_server.py

@@ -44,6 +44,7 @@
 import time
 import typing
 from collections.abc import Iterable
+from dataclasses import dataclass
 from logging import StreamHandler
 from logging.handlers import RotatingFileHandler
 from threading import Thread
@@ -184,6 +185,19 @@ def filter(self, record):
             return False
 
 
+@dataclass(frozen=True)
+class DeviceServerOptions:
+    """Class to define configuration for a device server.
+
+    The different fields map to the different ``device-server``
+    command line options.
+
+    """
+
+    config_fpath: str
+    logging_level: int
+
+
 def _check_autoproxy_feature() -> None:
     # AUTOPROXY is enabled by default.  If it is disabled there must
     # be a reason so raise an error instead of silently enabling it.
@@ -228,6 +242,7 @@ class DeviceServer(multiprocessing.Process):
 
     Args:
         device_def: definition of the device.
+        options: configuration for the device server.
         id_to_host: host or mapping of device identifiers to hostname.
         id_to_port: map or mapping of device identifiers to port
             number.
@@ -239,12 +254,14 @@ class DeviceServer(multiprocessing.Process):
     def __init__(
         self,
         device_def,
+        options: DeviceServerOptions,
         id_to_host: typing.Mapping[str, str],
         id_to_port: typing.Mapping[str, int],
         exit_event: typing.Optional[multiprocessing.Event] = None,
     ):
         # The device to serve.
         self._device_def = device_def
+        self._options = options
         self._devices: typing.Dict[str, microscope.abc.Device] = {}
         # Where to serve it.
         self._id_to_host = id_to_host
@@ -262,6 +279,7 @@ def clone(self):
         """
         return DeviceServer(
             self._device_def,
+            self._options,
             self._id_to_host,
             self._id_to_port,
             exit_event=self.exit_event,
@@ -283,6 +301,8 @@ def run(self):
         for handler in list(root_logger.handlers):
             root_logger.removeHandler(handler)
 
+        root_logger.setLevel(self._options.logging_level)
+
         # Later, we'll log to one file per server, with a filename
         # based on a unique identifier for the device. Some devices
         # don't have UIDs available until after initialization, so
@@ -369,7 +389,7 @@ def run(self):
                 _logger.error("Failure to shutdown device %s", device, ex)
 
 
-def serve_devices(devices, exit_event=None):
+def serve_devices(devices, options: DeviceServerOptions, exit_event=None):
     root_logger = logging.getLogger()
 
     log_handler = RotatingFileHandler("__MAIN__.log")
@@ -443,7 +463,11 @@ def term_func(sig, frame):
         for dev in devs:
             servers.append(
                 DeviceServer(
-                    dev, uid_to_host, uid_to_port, exit_event=exit_event
+                    dev,
+                    options,
+                    uid_to_host,
+                    uid_to_port,
+                    exit_event=exit_event,
                 )
             )
             servers[-1].start()
@@ -517,7 +541,7 @@ def keep_alive():
     return
 
 
-def _parse_cmd_line_args(args: typing.Sequence[str]) -> argparse.Namespace:
+def _parse_cmd_line_args(args: typing.Sequence[str]) -> DeviceServerOptions:
     parser = argparse.ArgumentParser(prog="device-server")
     parser.add_argument(
         "--logging-level",
@@ -534,7 +558,11 @@ def _parse_cmd_line_args(args: typing.Sequence[str]) -> argparse.Namespace:
         metavar="CONFIG-FILEPATH",
         help="Path to the configuration file",
     )
-    return parser.parse_args(args)
+    parsed = parser.parse_args(args)
+    return DeviceServerOptions(
+        config_fpath=parsed.config_fpath,
+        logging_level=getattr(logging, parsed.logging_level.upper()),
+    )
 
 
 def _load_source(filepath):
@@ -557,20 +585,20 @@ def validate_devices(configfile):
 
 
 def main(argv: typing.Sequence[str]) -> int:
-    args = _parse_cmd_line_args(argv[1:])
+    options = _parse_cmd_line_args(argv[1:])
 
     root_logger = logging.getLogger()
-    root_logger.setLevel(args.logging_level.upper())
+    root_logger.setLevel(options.logging_level)
 
     stderr_handler = StreamHandler(sys.stderr)
     stderr_handler.setFormatter(_create_log_formatter("device-server"))
     root_logger.addHandler(stderr_handler)
 
     root_logger.addFilter(Filter())
 
-    devices = validate_devices(args.config_fpath)
+    devices = validate_devices(options.config_fpath)
 
-    serve_devices(devices)
+    serve_devices(devices, options)
 
     return 0
 

microscope/testsuite/test_device_server.py

@@ -109,8 +109,12 @@ class BaseTestServeDevices(unittest.TestCase):
 
     @_patch_out_device_server_logs
     def setUp(self):
+        options = microscope.device_server.DeviceServerOptions(
+            config_fpath="", logging_level=logging.INFO,
+        )
         self.p = multiprocessing.Process(
-            target=microscope.device_server.serve_devices, args=(self.DEVICES,)
+            target=microscope.device_server.serve_devices,
+            args=(self.DEVICES, options),
         )
         self.p.start()
         time.sleep(1)
@@ -266,6 +270,9 @@ class TestServingFloatingDevicesWithWrongUID(BaseTestDeviceServer):
             {"uid": "foo", "index": 0},
             uid="bar",
         ),
+        microscope.device_server.DeviceServerOptions(
+            config_fpath="", logging_level=logging.INFO,
+        ),
         {"bar": "127.0.0.1"},
         {"bar": 8001},
         multiprocessing.Event(),
@@ -295,6 +302,9 @@ class TestFunctionInDeviceDefinition(BaseTestDeviceServer):
             "localhost",
             8001,
         ),
+        microscope.device_server.DeviceServerOptions(
+            config_fpath="", logging_level=logging.INFO,
+        ),
         {},
         {},
         multiprocessing.Event(),

microscope/win32.py

@@ -31,6 +31,7 @@
 """
 
 
+import logging
 import multiprocessing
 import os
 import sys
@@ -98,11 +99,19 @@ def SvcDoRun(self):
         self.log("Logging at %s." % os.getcwd())
         self.ReportServiceStatus(win32service.SERVICE_RUNNING)
 
-        from microscope.device_server import serve_devices, validate_devices
+        from microscope.device_server import (
+            serve_devices,
+            validate_devices,
+            DeviceServerOptions,
+        )
+
+        options = DeviceServerOptions(
+            config_fpath=configfile, logging_level=logging.INFO,
+        )
 
         try:
             devices = validate_devices(configfile)
-            serve_devices(devices, self.stop_event)
+            serve_devices(devices, options, self.stop_event)
         except Exception as e:
             servicemanager.LogErrorMsg(str(e))
             # Exit with non-zero error code so Windows will attempt to restart.

pyproject.toml

@@ -15,7 +15,7 @@ multi_line_output = 3  # multi lineoutput 3 is vert-hanging
 
 [tool.black]
 line-length = 79
-target-version = ['py36', 'py37', 'py38']
+target-version = ['py37', 'py38']
 
 
 [tool.pylint.FORMAT]

setup.py

@@ -186,7 +186,7 @@ def make_distribution(self):
         "Tracker": "https://github.com/python-microscope/microscope",
     },
     packages=setuptools.find_packages(),
-    python_requires=">=3.6",
+    python_requires=">=3.7",
     install_requires=["Pillow", "Pyro4", "hidapi", "numpy", "pyserial"],
     extras_require={"GUI": ["PySide2"]},
     entry_points={