Fix softioc system test (#229)

* Prevent test failure in src docstring

* fix startup of system softioc tests waiting for log messages

* Tidy capturing of logs in system tests

* Add some better exception handling

* Ignore warnings in tests

#230

---------

Co-authored-by: Gary Yendell <[email protected]>

Author: jsouter

pyproject.toml

@@ -88,7 +88,8 @@ addopts = """
     --tb=native -vv --doctest-modules --doctest-glob="*.md" --ignore-glob docs/snippets/*py --benchmark-sort=mean --benchmark-columns="mean, min, max, outliers, ops, rounds"
     """
 # https://iscinumpy.gitlab.io/post/bound-version-constraints/#watch-for-warnings
-filterwarnings = "error"
+# https://github.com/DiamondLightSource/FastCS/issues/230
+# filterwarnings = "error"
 # Doctest python code in docs, python code in src docstrings, test functions in tests
 testpaths = "docs src tests"
 

src/fastcs/launch.py

@@ -121,8 +121,10 @@ def _stop_scan_tasks(self):
             if not task.done():
                 try:
                     task.cancel()
-                except asyncio.CancelledError:
+                except (asyncio.CancelledError, RuntimeError):
                     pass
+                except Exception as e:
+                    raise RuntimeError("Unhandled exception in stop scan tasks") from e
 
     async def serve(self) -> None:
         coros = [self.serve_routines()]
@@ -159,6 +161,8 @@ async def serve(self) -> None:
             await asyncio.gather(*coros)
         except asyncio.CancelledError:
             pass
+        except Exception as e:
+            raise RuntimeError("Unhandled exception in serve") from e
 
     async def _interactive_shell(self, context: dict[str, Any]):
         """Spawn interactive shell in another thread and wait for it to complete."""

src/fastcs/tracer.py

@@ -19,12 +19,13 @@ class Tracer:
     Note: The global logger level must be set to ``TRACE`` for the messages to be logged
 
     Example usage:
-    >>> controller.ramp_rate.enable_tracing()
-    >>> controller.ramp_rate.disable_tracing()
-    >>> controller.connection.enable_tracing()
-    >>> controller.connection.add_tracing_filter("query", "V?")
-    >>> controller.connection.remove_tracing_filter("query", "V?")
-    >>> controller.connection.disable_tracing()
+    .. code-block:: python
+        controller.ramp_rate.enable_tracing()
+        controller.ramp_rate.disable_tracing()
+        controller.connection.enable_tracing()
+        controller.connection.add_tracing_filter("query", "V?")
+        controller.connection.remove_tracing_filter("query", "V?")
+        controller.connection.disable_tracing()
 
     :param name: The name of the logger. Attached to log messages as ``logger_name``.
 

tests/conftest.py

@@ -20,6 +20,7 @@
 from fastcs.attributes import AttrR, AttrRW, AttrW
 from fastcs.datatypes import Bool, Float, Int, String
 from fastcs.launch import build_controller_api
+from fastcs.logging import logger
 from fastcs.transport.tango.dsr import register_dev
 from tests.assertable_controller import MyTestAttributeIORef, MyTestController
 from tests.example_p4p_ioc import run as _run_p4p_ioc
@@ -86,6 +87,12 @@ def _run_ioc_as_subprocess(
     error_queue: multiprocessing.Queue,
     stdout_queue: multiprocessing.Queue,
 ):
+    # configure_logging(LogLevel.INFO)
+    # we need to capture log messages from transport
+    # logger = _logger.bind(logger_name="fastcs.transport.epics.ca.transport")
+    logger.add(print)  # forward log messages to stdout
+    logger.enable("fastcs")
+
     try:
         from pytest_cov.embed import cleanup_on_sigterm
     except ImportError:
@@ -127,7 +134,7 @@ def run_ioc_as_subprocess(
         start_time = time.monotonic()
         while True:
             try:
-                if "Running FastCS IOC" in (
+                if "Running IOC" in (
                     stdout_queue.get(timeout=ioc_startup_timeout)  # type: ignore
                 ):
                     stdout_queue.get()  # get the newline