fix(logging): configure each stdlib logger once and leave its name and preset level alone (#358)

Author: lesnik512

lite_bootstrap/instruments/logging_factory.py

@@ -126,12 +126,16 @@ def __init__(
             config: "_MemoryLoggerFactoryConfig",
             **kwargs: typing.Any,  # noqa: ANN401
         ) -> None:
+            kwargs["ignore_frame_names"] = [*(kwargs.get("ignore_frame_names") or ()), __name__]
             super().__init__(*args, **kwargs)
             self.config = config
-            self._created_handlers: list[tuple[logging.Logger, logging.handlers.MemoryHandler]] = []
+            self._created_handlers: dict[logging.Logger, logging.handlers.MemoryHandler] = {}
+            self._leveled_loggers: set[logging.Logger] = set()
 
         def __call__(self, *args: typing.Any) -> logging.Logger:  # noqa: ANN401
             logger: typing.Final = super().__call__(*args)
+            if logger in self._created_handlers:
+                return logger
             stream_handler: typing.Final = logging.StreamHandler(stream=self.config.log_stream)
             stream_handler.setFormatter(_RenderedLineFormatter())
             handler: typing.Final = logging.handlers.MemoryHandler(
@@ -140,20 +144,25 @@ def __call__(self, *args: typing.Any) -> logging.Logger:  # noqa: ANN401
                 target=stream_handler,
             )
             logger.addHandler(handler)
-            logger.setLevel(self.config.logging_log_level)
+            if logger.level == logging.NOTSET:
+                logger.setLevel(self.config.logging_log_level)
+                self._leveled_loggers.add(logger)
             logger.propagate = False
-            self._created_handlers.append((logger, handler))
+            self._created_handlers[logger] = handler
             return logger
 
         def close_handlers(self) -> None:
-            for created_logger, handler in self._created_handlers:
+            for created_logger, handler in self._created_handlers.items():
                 created_logger.removeHandler(handler)
                 created_logger.propagate = True
+                if created_logger in self._leveled_loggers:
+                    created_logger.setLevel(logging.NOTSET)
                 target = handler.target
                 handler.close()
                 if target is not None:
                     target.close()
             self._created_handlers.clear()
+            self._leveled_loggers.clear()
 
 
 __getattr__ = deprecated_module_getattr(__name__, _DEPRECATED_PROTOCOLS)

tests/instruments/test_logging_instrument.py

@@ -129,6 +129,63 @@ def test_memory_logger_factory_error() -> None:
     assert error_message in test_stream.getvalue()
 
 
+def _unbuffered_factory(stream: StringIO) -> MemoryLoggerFactory:
+    return MemoryLoggerFactory(
+        config=_MemoryLoggerFactoryConfig(
+            logging_buffer_capacity=0,
+            logging_flush_level=logging.ERROR,
+            logging_log_level=logging.INFO,
+            log_stream=stream,
+        ),
+    )
+
+
+def test_memory_logger_factory_configures_each_logger_once() -> None:
+    test_stream = StringIO()
+    logger_factory = _unbuffered_factory(test_stream)
+    try:
+        first = logger_factory("configured_once")
+        second = logger_factory("configured_once")
+        second.info("one line")
+
+        assert first is second
+        assert len(first.handlers) == 1
+        assert test_stream.getvalue().splitlines() == ["one line"]
+    finally:
+        logger_factory.close_handlers()
+
+    assert logging.getLogger("configured_once").handlers == []
+
+
+def test_memory_logger_factory_names_unnamed_logger_after_caller() -> None:
+    logger_factory = _unbuffered_factory(StringIO())
+    try:
+        assert logger_factory().name == __name__
+    finally:
+        logger_factory.close_handlers()
+
+
+def test_memory_logger_factory_keeps_a_level_set_beforehand() -> None:
+    preset_logger = logging.getLogger("preset_level")
+    preset_logger.setLevel(logging.DEBUG)
+    logger_factory = _unbuffered_factory(StringIO())
+    try:
+        assert logger_factory("preset_level").level == logging.DEBUG
+        assert logger_factory("unset_level").level == logging.INFO
+    finally:
+        logger_factory.close_handlers()
+        preset_logger.setLevel(logging.NOTSET)
+        logging.getLogger("unset_level").setLevel(logging.NOTSET)
+
+
+def test_memory_logger_factory_close_handlers_restores_the_level_it_set() -> None:
+    logger_factory = _unbuffered_factory(StringIO())
+    logger_factory("restored_level")
+    logger_factory.close_handlers()
+
+    assert logging.getLogger("restored_level").level == logging.NOTSET
+
+
 def test_logging_instrument_lifecycle_replay(logging_mock: LoggingMock) -> None:
     instrument = LoggingInstrument(
         bootstrap_config=LoggingConfig(