From 1a65dd4afe82a50ccfea644b9268d527ee6324c1 Mon Sep 17 00:00:00 2001 From: david Date: Mon, 19 Oct 2026 15:02:12 +0200 Subject: [PATCH] fix(logging): stop knowledge_mapper log records being emitted twice The knowledge_mapper logger attaches its own handler on import but did not disable propagation. If the host application also configures the root logger (e.g. via logging.basicConfig()), every record from knowledge_mapper (and its child loggers) was handled once by the library's own handler and again when it propagated up to the root logger's handler, producing duplicate log lines in differing formats. Set propagate = False on the knowledge_mapper logger so records are only emitted via its own handler. Document this behavior in CONTEXT.md, including how host applications can opt out. Fixes #72 Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- CONTEXT.md | 6 +++++ src/knowledge_mapper/__init__.py | 14 +++++++++-- tests/test_logging.py | 43 ++++++++++++++++++++++++++++++++ 3 files changed, 61 insertions(+), 2 deletions(-) create mode 100644 tests/test_logging.py 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)