diff --git a/src/labthings_fastapi/logs.py b/src/labthings_fastapi/logs.py index 2fbeac60..43efc848 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,14 @@ 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 INFO. """ - THING_LOGGER.setLevel(logging.INFO) + if level is not None: + THING_LOGGER.setLevel(level) + else: + THING_LOGGER.setLevel(logging.INFO) + if not any( isinstance(h, DequeByInvocationIDHandler) for h in THING_LOGGER.handlers ): diff --git a/src/labthings_fastapi/server/__init__.py b/src/labthings_fastapi/server/__init__.py index 01c7f73d..148dd850 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,15 +117,17 @@ 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. """ - 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. diff --git a/src/labthings_fastapi/server/cli.py b/src/labthings_fastapi/server/cli.py index d848b89b..66f854cd 100644 --- a/src/labthings_fastapi/server/cli.py +++ b/src/labthings_fastapi/server/cli.py @@ -56,6 +56,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,10 +154,11 @@ def serve_from_cli( option is not specified. """ args = parse_args(argv) + try: config, server = None, None config = config_from_args(args) - server = ThingServer.from_config(config) + 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) diff --git a/tests/test_logs.py b/tests/test_logs.py index dd4b51d3..ead3152d 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 @@ -20,6 +21,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 @@ -45,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 @@ -169,6 +177,66 @@ 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 INFO + 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 + + # 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() + + +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 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) + + # Check that the debug message was captured + assert "Debug message during __init__" in caplog.text + + # Reset back to INFO + reset_thing_logger() + + def test_add_thing_log_destination(): """Check the module-level function to add an invocation log destination.""" reset_thing_logger()