diff --git a/CONTEXT.md b/CONTEXT.md index 87443db..bf71675 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -477,6 +477,12 @@ uv run ruff format . # format --- +## Logging + +`knowledge_mapper` attaches its own `StreamHandler`/formatter to the `knowledge_mapper` logger on import, so log output looks reasonable out of the box even if the host application never calls `logging.basicConfig()`. This logger has `propagate = False`, so records aren't also emitted via ancestor loggers (e.g. the root logger) the host application may configure — otherwise every record would be logged twice, once per handler. Host applications that want full control over formatting/handling of `knowledge_mapper`'s log records can remove its handler (`logging.getLogger("knowledge_mapper").handlers.clear()`) and/or set `propagate = True` to route records through their own logging configuration instead. + +--- + ## Legacy Code The pre-overhaul, config-file-driven mapper implementation has been removed from the repository. The `mapper-legacy` git tag marks the last legacy release and preserves the full history. diff --git a/src/knowledge_mapper/__init__.py b/src/knowledge_mapper/__init__.py index 01dec20..ffb0dc3 100644 --- a/src/knowledge_mapper/__init__.py +++ b/src/knowledge_mapper/__init__.py @@ -24,7 +24,17 @@ __version__ = "0.1.0rc1" +# The package attaches its own handler/formatter so log output is sensible +# out of the box, even if the host application never calls +# `logging.basicConfig()`. Propagation to ancestor loggers (e.g. the root +# logger, which the host application may configure separately) is disabled +# so records aren't emitted twice -- once via this handler, once via the +# host's. Host applications that want to fully control formatting/handling of +# knowledge_mapper's log records can remove `_handler` from this logger (or +# re-enable propagate) and configure the root logger instead. +_logger = logging.getLogger(__name__) _handler = logging.StreamHandler() _handler.setFormatter(logging.Formatter("%(asctime)s [%(levelname)s] %(message)s")) -logging.getLogger(__name__).addHandler(_handler) -logging.getLogger(__name__).setLevel(logging.DEBUG) +_logger.addHandler(_handler) +_logger.setLevel(logging.DEBUG) +_logger.propagate = False diff --git a/tests/test_logging.py b/tests/test_logging.py new file mode 100644 index 0000000..4ef81b6 --- /dev/null +++ b/tests/test_logging.py @@ -0,0 +1,43 @@ +"""Regression tests for https://github.com/TNO/knowledge-mapper/issues/72. + +Host applications often call `logging.basicConfig()` (or otherwise attach a +handler to the root logger) in addition to knowledge_mapper's own handler. If +knowledge_mapper's logger propagates records to the root logger, every record +is emitted twice: once by knowledge_mapper's own handler, once by the host's. +""" + +import logging + +import knowledge_mapper + + +def test_package_logger_does_not_propagate(): + """knowledge_mapper's logger must not propagate to ancestor loggers (e.g. + root), since it already attaches its own handler.""" + logger = logging.getLogger(knowledge_mapper.__name__) + assert logger.propagate is False + + +def test_log_record_does_not_reach_host_configured_root_handler(): + """Simulates a host application that configures the root logger (e.g. via + `logging.basicConfig()`) in addition to knowledge_mapper's own handler. + The record must not be handled twice, i.e. it must not reach the root + logger's handler at all.""" + root = logging.getLogger() + received: list[logging.LogRecord] = [] + + class _RecordingHandler(logging.Handler): + def emit(self, record: logging.LogRecord) -> None: + received.append(record) + + host_handler = _RecordingHandler() + root.addHandler(host_handler) + previous_root_level = root.level + root.setLevel(logging.DEBUG) + try: + child_logger = logging.getLogger(f"{knowledge_mapper.__name__}.some_module") + child_logger.debug("hello") + assert received == [] + finally: + root.removeHandler(host_handler) + root.setLevel(previous_root_level)