From 4419bba303a4438bd7a14677cd9369b301a214c6 Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 16:36:59 +0000 Subject: [PATCH 01/10] Add --debug argument to CLI to make the THING LOGGER level configurable between debug and info. Unit test also added. --- src/labthings_fastapi/logs.py | 15 +++++++++++---- src/labthings_fastapi/server/cli.py | 10 ++++++++++ tests/test_cli_debug.py | 28 ++++++++++++++++++++++++++++ 3 files changed, 49 insertions(+), 4 deletions(-) create mode 100644 tests/test_cli_debug.py diff --git a/src/labthings_fastapi/logs.py b/src/labthings_fastapi/logs.py index 2fbeac60..ce665f18 100644 --- a/src/labthings_fastapi/logs.py +++ b/src/labthings_fastapi/logs.py @@ -79,11 +79,11 @@ def emit(self, record: logging.LogRecord) -> None: pass # If there's no destination for a particular log, ignore it. -def configure_thing_logger() -> None: +def configure_thing_logger(level: int | None = None) -> None: """Set up the logger for thing instances. - We always set the logger for thing instances to level INFO, as this - is currently used to relay progress to the client. + We always set the logger for thing instances to level INFO by default, + as this is currently used to relay progress to the client. This function will collect logs on a per-invocation basis by adding a `.DequeByInvocationIDHandler` to the log. Only one @@ -93,8 +93,15 @@ def configure_thing_logger() -> None: a filter to add invocation ID is not possible. Instead, we attach a filter to the handler, which filters all the records that propagate to it (i.e. anything that starts with ``labthings_fastapi.things``). + + :param level: the logging level to use. If not specified, we use the + current level, or INFO if no level has been set. """ - THING_LOGGER.setLevel(logging.INFO) + if level is not None: + THING_LOGGER.setLevel(level) + elif THING_LOGGER.level == logging.NOTSET: + THING_LOGGER.setLevel(logging.INFO) + if not any( isinstance(h, DequeByInvocationIDHandler) for h in THING_LOGGER.handlers ): diff --git a/src/labthings_fastapi/server/cli.py b/src/labthings_fastapi/server/cli.py index d848b89b..72f63305 100644 --- a/src/labthings_fastapi/server/cli.py +++ b/src/labthings_fastapi/server/cli.py @@ -19,6 +19,7 @@ """ from argparse import ArgumentParser, Namespace +import logging import sys from typing import Literal, Optional, overload @@ -28,6 +29,7 @@ from . import ThingServer from . import fallback from .config_model import ThingServerConfig, ThingImportFailure +from ..logs import configure_thing_logger def get_default_parser() -> ArgumentParser: @@ -56,6 +58,11 @@ def get_default_parser() -> ArgumentParser: default=5000, help="Bind socket to this port. If 0, an available port will be picked.", ) + parser.add_argument( + "--debug", + action="store_true", + help="Enable debug logging.", + ) return parser @@ -149,6 +156,9 @@ def serve_from_cli( option is not specified. """ args = parse_args(argv) + if args.debug: + configure_thing_logger(logging.DEBUG) + try: config, server = None, None config = config_from_args(args) diff --git a/tests/test_cli_debug.py b/tests/test_cli_debug.py new file mode 100644 index 00000000..65a231a2 --- /dev/null +++ b/tests/test_cli_debug.py @@ -0,0 +1,28 @@ +import logging +from labthings_fastapi.server.cli import serve_from_cli +from labthings_fastapi.logs import THING_LOGGER + + +def test_cli_debug_flag(): + """ + Test that using the --debug flag sets the logger level to DEBUG, + and that not using it leaves the logger level at INFO. + """ + # Reset logger level to NOTSET + THING_LOGGER.setLevel(logging.NOTSET) + + # Run without --debug + # We use dry_run=True to avoid starting uvicorn + # We need a dummy config + dummy_json = '{"things": {}}' + serve_from_cli(["--json", dummy_json], dry_run=True) + + assert THING_LOGGER.level == logging.INFO + + # Reset logger level + THING_LOGGER.setLevel(logging.NOTSET) + + # Run with --debug + serve_from_cli(["--json", dummy_json, "--debug"], dry_run=True) + + assert THING_LOGGER.level == logging.DEBUG From 4ad8c48a4dcc810b25993b1834c48c972bf8437e Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 16:48:51 +0000 Subject: [PATCH 02/10] Reset log level at end of test --- tests/test_cli_debug.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/tests/test_cli_debug.py b/tests/test_cli_debug.py index 65a231a2..e40b183c 100644 --- a/tests/test_cli_debug.py +++ b/tests/test_cli_debug.py @@ -26,3 +26,6 @@ def test_cli_debug_flag(): serve_from_cli(["--json", dummy_json, "--debug"], dry_run=True) assert THING_LOGGER.level == logging.DEBUG + + # Reset logger level to NOTSET + THING_LOGGER.setLevel(logging.NOTSET) From c967538ddc175f752ee49b5c425928c855fed064 Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 17:17:10 +0000 Subject: [PATCH 03/10] Move test into correct file --- tests/test_cli_debug.py | 31 ------------------------------- tests/test_logs.py | 30 ++++++++++++++++++++++++++++++ 2 files changed, 30 insertions(+), 31 deletions(-) delete mode 100644 tests/test_cli_debug.py diff --git a/tests/test_cli_debug.py b/tests/test_cli_debug.py deleted file mode 100644 index e40b183c..00000000 --- a/tests/test_cli_debug.py +++ /dev/null @@ -1,31 +0,0 @@ -import logging -from labthings_fastapi.server.cli import serve_from_cli -from labthings_fastapi.logs import THING_LOGGER - - -def test_cli_debug_flag(): - """ - Test that using the --debug flag sets the logger level to DEBUG, - and that not using it leaves the logger level at INFO. - """ - # Reset logger level to NOTSET - THING_LOGGER.setLevel(logging.NOTSET) - - # Run without --debug - # We use dry_run=True to avoid starting uvicorn - # We need a dummy config - dummy_json = '{"things": {}}' - serve_from_cli(["--json", dummy_json], dry_run=True) - - assert THING_LOGGER.level == logging.INFO - - # Reset logger level - THING_LOGGER.setLevel(logging.NOTSET) - - # Run with --debug - serve_from_cli(["--json", dummy_json, "--debug"], dry_run=True) - - assert THING_LOGGER.level == logging.DEBUG - - # Reset logger level to NOTSET - THING_LOGGER.setLevel(logging.NOTSET) diff --git a/tests/test_logs.py b/tests/test_logs.py index dd4b51d3..38ef3c66 100644 --- a/tests/test_logs.py +++ b/tests/test_logs.py @@ -20,6 +20,7 @@ import labthings_fastapi as lt from labthings_fastapi.exceptions import LogConfigurationError from labthings_fastapi.testing import create_thing_without_server +from labthings_fastapi.server.cli import serve_from_cli from .temp_client import poll_task @@ -169,6 +170,35 @@ def test_configure_thing_logger(): assert dest[0].msg == "Test" +def test_cli_debug_flag(): + """ + Test that using the --debug flag sets the logger level to DEBUG, + and that not using it leaves the logger level at INFO. + """ + # Reset logger level to NOTSET + reset_thing_logger() + + # Then configure it + logs.configure_thing_logger() + + # Run without --debug + # We use dry_run=True to avoid starting uvicorn + # We need a dummy config + dummy_json = '{"things": {}}' + serve_from_cli(["--json", dummy_json], dry_run=True) + + assert logs.THING_LOGGER.level == logging.INFO + + reset_thing_logger() + + # Run with --debug + serve_from_cli(["--json", dummy_json, "--debug"], dry_run=True) + + assert logs.THING_LOGGER.level == logging.DEBUG + + reset_thing_logger() + + def test_add_thing_log_destination(): """Check the module-level function to add an invocation log destination.""" reset_thing_logger() From cbe9dfed6a3a87986613eb7a4d5a1d46c6635bc0 Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 17:59:03 +0000 Subject: [PATCH 04/10] Reset back to info --- src/labthings_fastapi/logs.py | 2 +- tests/test_logs.py | 3 +-- 2 files changed, 2 insertions(+), 3 deletions(-) diff --git a/src/labthings_fastapi/logs.py b/src/labthings_fastapi/logs.py index ce665f18..2d110d8f 100644 --- a/src/labthings_fastapi/logs.py +++ b/src/labthings_fastapi/logs.py @@ -99,7 +99,7 @@ def configure_thing_logger(level: int | None = None) -> None: """ if level is not None: THING_LOGGER.setLevel(level) - elif THING_LOGGER.level == logging.NOTSET: + else: THING_LOGGER.setLevel(logging.INFO) if not any( diff --git a/tests/test_logs.py b/tests/test_logs.py index 38ef3c66..8d280dd7 100644 --- a/tests/test_logs.py +++ b/tests/test_logs.py @@ -189,13 +189,12 @@ def test_cli_debug_flag(): assert logs.THING_LOGGER.level == logging.INFO - reset_thing_logger() - # Run with --debug serve_from_cli(["--json", dummy_json, "--debug"], dry_run=True) assert logs.THING_LOGGER.level == logging.DEBUG + # Reset back to info reset_thing_logger() From b00fc5f28a3536c5e08b46ebebc4dad24c14bd1a Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 18:03:15 +0000 Subject: [PATCH 05/10] Move order for setting debug to after server initialises --- src/labthings_fastapi/server/cli.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/labthings_fastapi/server/cli.py b/src/labthings_fastapi/server/cli.py index 72f63305..6a9f5569 100644 --- a/src/labthings_fastapi/server/cli.py +++ b/src/labthings_fastapi/server/cli.py @@ -156,13 +156,13 @@ def serve_from_cli( option is not specified. """ args = parse_args(argv) - if args.debug: - configure_thing_logger(logging.DEBUG) try: config, server = None, None config = config_from_args(args) server = ThingServer.from_config(config) + if args.debug: + configure_thing_logger(logging.DEBUG) if dry_run: return server uvicorn.run(server.app, host=args.host, port=args.port) From 4a2c1a5f402335ba4a78381d9eb8f45cf8ffe727 Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 18:08:04 +0000 Subject: [PATCH 06/10] Update docstring --- src/labthings_fastapi/logs.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/src/labthings_fastapi/logs.py b/src/labthings_fastapi/logs.py index 2d110d8f..43efc848 100644 --- a/src/labthings_fastapi/logs.py +++ b/src/labthings_fastapi/logs.py @@ -94,8 +94,7 @@ def configure_thing_logger(level: int | None = None) -> None: the handler, which filters all the records that propagate to it (i.e. anything that starts with ``labthings_fastapi.things``). - :param level: the logging level to use. If not specified, we use the - current level, or INFO if no level has been set. + :param level: the logging level to use. If not specified, we use INFO. """ if level is not None: THING_LOGGER.setLevel(level) From 2019091d5c244952e7bda693790127b990b91c2a Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 18:41:10 +0000 Subject: [PATCH 07/10] Respond to review comment --- src/labthings_fastapi/server/__init__.py | 13 +++++++++++-- src/labthings_fastapi/server/cli.py | 6 +----- 2 files changed, 12 insertions(+), 7 deletions(-) diff --git a/src/labthings_fastapi/server/__init__.py b/src/labthings_fastapi/server/__init__.py index 01c7f73d..80802239 100644 --- a/src/labthings_fastapi/server/__init__.py +++ b/src/labthings_fastapi/server/__init__.py @@ -10,6 +10,7 @@ from typing import Any, AsyncGenerator, Optional, TypeVar from typing_extensions import Self import os +import logging from fastapi import FastAPI, Request from fastapi.middleware.cors import CORSMiddleware @@ -66,6 +67,7 @@ def __init__( things: ThingsConfig, settings_folder: Optional[str] = None, application_config: Optional[Mapping[str, Any]] = None, + debug: bool = False, ) -> None: r"""Initialise a LabThings server. @@ -86,9 +88,12 @@ def __init__( application. This is not processed by LabThings. Each `.Thing` can access application. This is not processed by LabThings. Each `.Thing` can access this via the Thing-Server interface. + :param debug: If ``True``, set the log level for `.Thing` instances to + DEBUG. """ self.startup_failure: dict | None = None - configure_thing_logger() # Note: this is safe to call multiple times. + # Note: this is safe to call multiple times. + configure_thing_logger(logging.DEBUG if debug else None) self._config = ThingServerConfig( things=things, settings_folder=settings_folder, @@ -112,14 +117,18 @@ def __init__( self._attach_things_to_server() @classmethod - def from_config(cls, config: ThingServerConfig) -> Self: + def from_config(cls, config: ThingServerConfig, debug: bool = False) -> Self: r"""Create a ThingServer from a configuration model. This is equivalent to ``ThingServer(**dict(config))``\ . :param config: The configuration parameters for the server. + :param debug: If ``True``, set the log level for `.Thing` instances to + DEBUG. :return: A `.ThingServer` configured as per the model. """ + if debug: + configure_thing_logger(logging.DEBUG) return cls(**dict(config)) def _set_cors_middleware(self) -> None: diff --git a/src/labthings_fastapi/server/cli.py b/src/labthings_fastapi/server/cli.py index 6a9f5569..66f854cd 100644 --- a/src/labthings_fastapi/server/cli.py +++ b/src/labthings_fastapi/server/cli.py @@ -19,7 +19,6 @@ """ from argparse import ArgumentParser, Namespace -import logging import sys from typing import Literal, Optional, overload @@ -29,7 +28,6 @@ from . import ThingServer from . import fallback from .config_model import ThingServerConfig, ThingImportFailure -from ..logs import configure_thing_logger def get_default_parser() -> ArgumentParser: @@ -160,9 +158,7 @@ def serve_from_cli( try: config, server = None, None config = config_from_args(args) - server = ThingServer.from_config(config) - if args.debug: - configure_thing_logger(logging.DEBUG) + server = ThingServer.from_config(config, True if args.debug else False) if dry_run: return server uvicorn.run(server.app, host=args.host, port=args.port) From eab463010a991f104a47c8c2ae0a8df8fc9aea87 Mon Sep 17 00:00:00 2001 From: Beth <167304066+bprobert97@users.noreply.github.com> Date: Wed, 4 Mar 2026 18:54:10 +0000 Subject: [PATCH 08/10] Update src/labthings_fastapi/server/__init__.py Co-authored-by: Julian Stirling --- src/labthings_fastapi/server/__init__.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/labthings_fastapi/server/__init__.py b/src/labthings_fastapi/server/__init__.py index 80802239..148dd850 100644 --- a/src/labthings_fastapi/server/__init__.py +++ b/src/labthings_fastapi/server/__init__.py @@ -127,9 +127,7 @@ def from_config(cls, config: ThingServerConfig, debug: bool = False) -> Self: DEBUG. :return: A `.ThingServer` configured as per the model. """ - if debug: - configure_thing_logger(logging.DEBUG) - return cls(**dict(config)) + return cls(**dict(config), debug=debug) def _set_cors_middleware(self) -> None: """Configure the server to allow requests from other origins. From f46174664266a38415ec84ef970fd9f98a907c65 Mon Sep 17 00:00:00 2001 From: Beth Probert Date: Wed, 4 Mar 2026 19:18:03 +0000 Subject: [PATCH 09/10] Add new test for capturing init logs --- tests/test_logs.py | 36 ++++++++++++++++++++++++++++++++++-- 1 file changed, 34 insertions(+), 2 deletions(-) diff --git a/tests/test_logs.py b/tests/test_logs.py index 8d280dd7..13224013 100644 --- a/tests/test_logs.py +++ b/tests/test_logs.py @@ -6,6 +6,7 @@ """ from collections import deque +import json import logging from types import EllipsisType import pytest @@ -46,6 +47,12 @@ def log_and_capture(self, msg: str) -> str: return logging_str +class ThingWithDebugInit(lt.Thing): + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.logger.debug("Debug message during __init__") + + def reset_thing_logger(): """Remove all handlers from the THING_LOGGER to reset it.""" logger = logs.THING_LOGGER @@ -175,7 +182,7 @@ def test_cli_debug_flag(): Test that using the --debug flag sets the logger level to DEBUG, and that not using it leaves the logger level at INFO. """ - # Reset logger level to NOTSET + # Reset logger level to INFO reset_thing_logger() # Then configure it @@ -194,7 +201,32 @@ def test_cli_debug_flag(): assert logs.THING_LOGGER.level == logging.DEBUG - # Reset back to info + # Reset back to INFO + reset_thing_logger() + + +def test_cli_debug_flag_with_thing(caplog): + """ + Test that using the --debug flag allows capturing debug logs during __init__. + """ + + # Reset logger level to INFO + reset_thing_logger() + + # Define a config that uses ThingWithDebugInit + # We use the full path to the class so it can be imported by LabThings + config_json = json.dumps( + {"things": {"my_thing": {"cls": "tests.test_logs.ThingWithDebugInit"}}} + ) + + # Run with --debug and capture logs + with caplog.at_level(logging.DEBUG, logger="labthings_fastapi.things"): + serve_from_cli(["--json", config_json, "--debug"], dry_run=True) + + # Check that the debug message was captured + assert "Debug message during __init__" in caplog.text + + # Reset back to INFO reset_thing_logger() From 049b6c2cbf82e9d11a0d0cbb7c47228a78318d83 Mon Sep 17 00:00:00 2001 From: Beth <167304066+bprobert97@users.noreply.github.com> Date: Thu, 5 Mar 2026 09:42:53 +0000 Subject: [PATCH 10/10] Update tests/test_logs.py Co-authored-by: Julian Stirling --- tests/test_logs.py | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/tests/test_logs.py b/tests/test_logs.py index 13224013..ead3152d 100644 --- a/tests/test_logs.py +++ b/tests/test_logs.py @@ -219,6 +219,13 @@ def test_cli_debug_flag_with_thing(caplog): {"things": {"my_thing": {"cls": "tests.test_logs.ThingWithDebugInit"}}} ) + # Run without --debug and capture logs + with caplog.at_level(logging.DEBUG, logger="labthings_fastapi.things"): + serve_from_cli(["--json", config_json], dry_run=True) + + # There are no logs + assert len(caplog.messages) == 0 + # Run with --debug and capture logs with caplog.at_level(logging.DEBUG, logger="labthings_fastapi.things"): serve_from_cli(["--json", config_json, "--debug"], dry_run=True)