diff --git a/docs/changes/newsfragments/7186.improved b/docs/changes/newsfragments/7186.improved new file mode 100644 index 000000000000..5512d655b3ec --- /dev/null +++ b/docs/changes/newsfragments/7186.improved @@ -0,0 +1,3 @@ +`InstrumentLoggerAdapter` now merges the extra dict from the log record with information +inserted by the LoggerAdapter. This makes it possible to add additional information to a +log message logged via the instruments log attribute e.g. `myinst.visa_log.info("message", extra={"this": "that"})` diff --git a/src/qcodes/logger/instrument_logger.py b/src/qcodes/logger/instrument_logger.py index 8c1fa1f8bda9..7e58a064136d 100644 --- a/src/qcodes/logger/instrument_logger.py +++ b/src/qcodes/logger/instrument_logger.py @@ -9,13 +9,14 @@ import collections.abc import logging +import sys from contextlib import contextmanager from typing import TYPE_CHECKING, Any from .logger import LevelType, get_console_handler, handler_level if TYPE_CHECKING: - from collections.abc import Iterator, MutableMapping, Sequence + from collections.abc import Iterator, Mapping, MutableMapping, Sequence from qcodes.instrument import InstrumentBase @@ -37,20 +38,61 @@ class InstrumentLoggerAdapter(logging.LoggerAdapter): """ + def __init__( + self, + logger: logging.Logger, + extra: Mapping[str, object] | None = None, + merge_extra: bool = True, + ): + """ + Initializes the InstrumentLoggerAdapter. + + Args: + logger: The logger to which the records will be passed. + extra: Extra context data to be added to the log records. + merge_extra: If True, the extra data will be merged with the + existing extra data in the log record. Otherwise the extra + data will replace the existing extra data in the log record. + + """ + # forward the merge_extra bool to the parent class if 3.13 + # otherwise assign it manually + if sys.version_info >= (3, 13): + super().__init__( + logger, + extra, + merge_extra=merge_extra, + ) + else: + super().__init__( + logger, + extra, + ) + self.merge_extra = merge_extra + def process( self, msg: str, kwargs: MutableMapping[str, Any] ) -> tuple[str, MutableMapping[str, Any]]: """ Returns the message and the kwargs for the handlers. """ - assert self.extra is not None - extra = dict(self.extra) - inst = extra.pop("instrument") + if self.extra is None: + extra = {} + else: + extra = dict(self.extra) + inst = extra.pop("instrument", None) full_name = getattr(inst, "full_name", None) instr_type = str(type(inst).__name__) - kwargs["extra"] = extra + # merge_extra is a bool attribute in 3.13 and later + # but not included in the typestub see + # https://github.com/python/typeshed/pull/14197 + # this makes it a type checking error in 3.13 but not in earlier versions + if self.merge_extra and "extra" in kwargs: # type: ignore[attr-defined,unused-ignore] + kwargs["extra"] = {**extra, **kwargs["extra"]} + else: + kwargs["extra"] = extra kwargs["extra"]["instrument_name"] = str(full_name) kwargs["extra"]["instrument_type"] = instr_type return f"[{full_name}({instr_type})] {msg}", kwargs diff --git a/tests/test_logger.py b/tests/test_logger.py index a28e0360df79..35cf8a933958 100644 --- a/tests/test_logger.py +++ b/tests/test_logger.py @@ -301,6 +301,26 @@ def test_instrument_connect_message(caplog: LogCaptureFixture) -> None: assert any(rec.msg == expected_con_mssg for rec in setup_records) +def test_instrument_logger_extra_info(awg5208, caplog: LogCaptureFixture) -> None: + """ + Test that the connect_message method logs as expected + + This test kind of belongs both here and in the tests for the instrument + code, but it is more conveniently written here + """ + extra_key = "some_extra" + extra_val = "extra_value" + + with caplog.at_level(logging.INFO): + awg5208.visa_log.info("test message") + assert not hasattr(caplog.records[0], extra_key) + caplog.clear() + + with caplog.at_level(logging.INFO): + awg5208.visa_log.info("test message", extra={extra_key: extra_val}) + assert getattr(caplog.records[0], extra_key) == "extra_value" + + def test_installation_info_logging() -> None: """ Test that installation information is logged upon starting the logging