Configure kanta event loggers at import time, inheriting the root level.

configure_logging() now runs with default arguments when kanta.logging is imported, attaching a plain stderr handler with propagate=False to the event loggers (kanta.bootstrap/migration/transaction) that carry Kanta-rendered output. No levels are set by default, so event output inherits the effective root level: a framework switching root between INFO in development and WARNING in production governs Kanta output too. Other configure_logging changes: channel enable flags use logger.disabled (propagate toggling no longer silences now that event loggers have their own handler), skiproot=False removes Kanta's handler and re-enables propagation so the root logger renders event output, and debug=True lifts only the DEBUG-emitting loggers (bootstrap, migration) to DEBUG instead of setting a level on the "kanta" parent.
2026-09-16 02:16:58 +00:00
parent a41f34d332
commit 44c1ed191e
5 changed files with 125 additions and 70 deletions
@@ -174,6 +174,7 @@ def resolve_user_key(value: str) -> str | None:
 - By default a transaction is logged with an `action by user` header followed by the diff lines. Added paths are colored green, deleted paths red. ANSI color codes are stripped after formatting when the standard error stream does not support color: `NO_COLOR` disables colors, `FORCE_COLOR` forces them, otherwise a tty check and a journald (`JOURNAL_STREAM`) check decide. The CLI (`python -m kanta`) strips its output the same way.
 - `kanta.transaction(..., extra=...)` accepts a display-only value that is shown after the action in the header. Anything other than `None` is printed str-converted (colored by Kanta), unless a custom logemit handler does something else with it; it is never persisted in the `ChangeRecord`.
 - `kanta.transaction(..., logdiff=False)` skips building and printing the diff body and logs only the header, which is useful for large or noisy changesets. Diff output can also be disabled globally with `configure_logging(diff=False)`; diff lines are emitted on the `kanta.transaction.diff` child logger so applications can route or silence them separately from the headers.
+- The event loggers `kanta.bootstrap`, `kanta.migration` and `kanta.transaction` are configured at import time (via `configure_logging()`, callable again to change the toggles): a plain stderr handler with no prefix and `propagate = False`, since Kanta renders this output itself. No levels are set, so they inherit the effective root level — a framework switching root between INFO in development and WARNING in production governs Kanta output too. Operational diagnostics (integrity errors, flush failures, rotation notes) use the plain `kanta` logger instead, propagating to the root logger and following the application's normal logging configuration.

 #### Log Emitters

@@ -24,7 +24,17 @@ transaction_logger = logging.getLogger("kanta.transaction")
 bootstrap_logger = logging.getLogger("kanta.bootstrap")
 migration_logger = logging.getLogger("kanta.migration")

-_logger = logging.getLogger(__name__)
+# Event loggers carry Kanta-rendered content (colored headers, diffs) and are
+# configured at import time; diagnostics from Kanta's internals use the plain
+# "kanta" logger so they follow the application's root logging configuration.
+EVENT_LOGGERS = ("kanta.bootstrap", "kanta.migration", "kanta.transaction")
+
+# Loggers that emit DEBUG-level events (file-opened summary, migration diffs).
+_DEBUG_LOGGERS = ("kanta.bootstrap", "kanta.migration")
+
+_PLAIN_HANDLER_NAME = "kanta.plain"
+
+_logger = logging.getLogger("kanta")

 # Pattern to match control characters and bidirectional overrides
 _UNSAFE_CHARS = re.compile(
@@ -148,7 +158,7 @@ def emit_event(
            try:
                proceed = handler(ev)
            except Exception:
-                _logger.exception("logemit callback failed, using default formatting")
+                _logger.exception("Kanta.logemit callback failed, using default formatting")
                break
            if not proceed:
                return
@@ -566,6 +576,15 @@ def log_change(
    )


+def _ensure_plain_handler(logger: logging.Logger) -> None:
+    """Attach Kanta's no-prefix stderr handler to *logger* if it has none."""
+    if not logger.handlers:
+        handler = logging.StreamHandler(sys.stderr)
+        handler.setFormatter(logging.Formatter("%(message)s"))
+        handler.name = _PLAIN_HANDLER_NAME
+        logger.addHandler(handler)
+
+
 def configure_logging(
    *,
    skiproot: bool = True,
@@ -577,13 +596,22 @@ def configure_logging(
 ) -> None:
    """Configure Kanta's default logging output.

+    Called once at import time with default arguments; call again to change
+    the toggles.  The event loggers ``kanta.bootstrap``, ``kanta.migration``
+    and ``kanta.transaction`` carry Kanta-rendered output (colored headers,
+    diffs) and print it bare through a plain stderr handler with
+    ``propagate = False``.  Diagnostic messages use the plain ``kanta``
+    logger and follow the application's root logging configuration.
+
+    No levels are set by default: the event loggers inherit the effective
+    level of the root logger, so a framework switching root between INFO in
+    development and WARNING in production governs Kanta output too.
+
    Args:
-        skiproot: If ``True`` (default), attach a no-prefix stderr handler to
-            the ``kanta`` logger and set ``kanta.propagate = False`` so Kanta
-            output is rendered directly without propagating to the root logger.
-            If ``False``, the child logger enable flags are still applied, but
-            no handler is added and ``kanta`` propagation is left untouched so
-            the application's root logger handles Kanta output.
+        skiproot: If ``True`` (default), event loggers print through Kanta's
+            own plain handler without propagating to the root logger.  If
+            ``False``, Kanta's handler is removed and propagation enabled so
+            the application's root logger renders event output instead.
        bootstrap: Whether bootstrap logs are enabled.
        migration: Whether migration logs are enabled.
        transaction: Whether transaction logs are enabled.
@@ -591,13 +619,10 @@ def configure_logging(
            only transaction headers are printed and diff formatting is
            skipped.  Per transaction this is controlled by the ``logdiff``
            argument of :meth:`Kanta.transaction`.
-        debug: Whether to set the ``kanta`` logger level to ``DEBUG`` instead
-            of ``INFO``.  This reveals debug-level output such as migration
-            diffs, which are hidden by default.
-
-    This helper is not called automatically; applications that want Kanta's
-    default output can call it, but most applications will configure logging
-    themselves.
+        debug: Whether to set the event loggers that emit DEBUG-level output
+            (bootstrap and migration) to ``DEBUG``, revealing output such as
+            the file-opened summary and migration diffs.  ``False`` resets
+            them to inheriting the root level.
    """
    logging.getLogger("kanta.transaction.diff").disabled = not diff

@@ -606,16 +631,21 @@ def configure_logging(
        ("kanta.migration", migration),
        ("kanta.transaction", transaction),
    ):
-        logging.getLogger(name).propagate = enabled
+        logging.getLogger(name).disabled = not enabled

-    if not skiproot:
-        return
+    for name in _DEBUG_LOGGERS:
+        logging.getLogger(name).setLevel(logging.DEBUG if debug else logging.NOTSET)

-    target = logging.getLogger("kanta")
-    target.propagate = False
+    for name in EVENT_LOGGERS:
+        logger = logging.getLogger(name)
+        if skiproot:
+            logger.propagate = False
+            _ensure_plain_handler(logger)
+        else:
+            logger.propagate = True
+            logger.handlers[:] = [
+                h for h in logger.handlers if h.name != _PLAIN_HANDLER_NAME
+            ]

-    if not target.handlers:
-        handler = logging.StreamHandler(sys.stderr)
-        handler.setFormatter(logging.Formatter("%(message)s"))
-        target.addHandler(handler)
-    target.setLevel(logging.DEBUG if debug else logging.INFO)
+
+configure_logging()  # Import-time default setup; call again to reconfigure.
@@ -1,3 +1,5 @@
+import logging
+
 import pytest

 from kanta.serialization import JsonSerializer, MsgPackSerializer
@@ -12,3 +14,20 @@ from kanta.serialization import JsonSerializer, MsgPackSerializer
 )
 def format_config(request):
    return request.param
+
+
+@pytest.fixture(autouse=True)
+def _kanta_event_loggers_propagate():
+    """Let kanta's event loggers propagate so caplog captures their records.
+
+    Kanta configures them with ``propagate = False`` at import time, which
+    would hide their records from pytest's root-logger capture handler.
+    """
+    names = ("kanta.bootstrap", "kanta.migration", "kanta.transaction")
+    loggers = [logging.getLogger(name) for name in names]
+    previous = [logger.propagate for logger in loggers]
+    for logger in loggers:
+        logger.propagate = True
+    yield
+    for logger, propagate in zip(loggers, previous):
+        logger.propagate = propagate
@@ -38,13 +38,23 @@ def _reset_kanta_loggers():
        logger.handlers.clear()


+def _setup_logging(**kwargs):
+    """Default kanta logging with the event loggers lifted to INFO.
+
+    Event loggers inherit the root level (WARNING under pytest); output
+    assertions need INFO.
+    """
+    configure_logging(**kwargs)
+    for name in ("kanta.bootstrap", "kanta.migration", "kanta.transaction"):
+        logging.getLogger(name).setLevel(logging.INFO)
+
+
 def _change_event(**kwargs) -> LogEvent:
    return LogEvent(kind="change", logger=transaction_logger, action="update", **kwargs)


 def test_emit_event_falsy_return_stops_chain(capsys):
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()
    calls = []

    def first(ev):
@@ -60,15 +70,13 @@ def test_emit_event_falsy_return_stops_chain(capsys):


 def test_emit_event_truthy_return_falls_back_to_default(capsys):
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()
    emit_event(_change_event(), [lambda ev: True])
    assert "update" in capsys.readouterr().err


 def test_emit_event_mutation_reaches_later_handlers_and_default(capsys):
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()
    calls = []

    def first(ev):
@@ -86,8 +94,7 @@ def test_emit_event_mutation_reaches_later_handlers_and_default(capsys):


 def test_emit_event_handler_error_falls_back_to_default(capsys):
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()

    def boom(ev):
        raise RuntimeError("broken")
@@ -109,8 +116,7 @@ def test_diff_lines_built_lazily(monkeypatch):


 def test_default_emit_created_and_migrated(capsys):
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()
    emit_event(LogEvent(kind="created", logger=bootstrap_logger, filename="x.kantadb"))
    emit_event(
        LogEvent(
@@ -129,8 +135,7 @@ def test_default_emit_created_and_migrated(capsys):

 def test_default_emit_strips_ansi_without_color_support(capsys, monkeypatch):
    """NO_COLOR output contains no ANSI codes; FORCE_COLOR keeps them."""
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()
    monkeypatch.setenv("NO_COLOR", "1")
    monkeypatch.delenv("FORCE_COLOR", raising=False)
    emit_event(_change_event(diff={"counter": 1}))
@@ -138,8 +143,7 @@ def test_default_emit_strips_ansi_without_color_support(capsys, monkeypatch):
    assert "\x1b[" not in err
    assert "counter" in err

-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()
    monkeypatch.setenv("FORCE_COLOR", "1")
    monkeypatch.delenv("NO_COLOR", raising=False)
    emit_event(_change_event(diff={"counter": 1}))
@@ -357,8 +361,7 @@ async def test_event_carries_kanta_instance(tmp_path, format_config):


 def test_header_is_settable_and_used_by_default_emit(capsys):
-    logging.getLogger("kanta").handlers.clear()
-    configure_logging()
+    _setup_logging()

    def restyle(ev):
        ev.header = f"CUSTOM {ev.action}"
@@ -39,33 +39,42 @@ def _reset_kanta_loggers():


 def test_configure_logging_defaults():
-    kanta_logger = logging.getLogger("kanta")
    configure_logging()
-    assert kanta_logger.level == logging.INFO
-    assert not kanta_logger.propagate
-    assert kanta_logger.handlers
+    for name in ("kanta.bootstrap", "kanta.migration", "kanta.transaction"):
+        logger = logging.getLogger(name)
+        assert logger.level == logging.NOTSET  # inherits the root level
+        assert not logger.propagate
+        assert logger.handlers


 def test_configure_logging_disables_specific_loggers():
    configure_logging(bootstrap=False, migration=False, transaction=False)
-    assert not logging.getLogger("kanta.bootstrap").propagate
-    assert not logging.getLogger("kanta.migration").propagate
-    assert not logging.getLogger("kanta.transaction").propagate
+    assert logging.getLogger("kanta.bootstrap").disabled
+    assert logging.getLogger("kanta.migration").disabled
+    assert logging.getLogger("kanta.transaction").disabled


-def test_configure_logging_skiproot_false_leaves_kanta_propagation():
-    kanta_logger = logging.getLogger("kanta")
-    kanta_logger.handlers.clear()
-    configure_logging(bootstrap=False, skiproot=False)
-    assert kanta_logger.propagate
-    assert not kanta_logger.handlers
-    assert not logging.getLogger("kanta.bootstrap").propagate
+def test_configure_logging_skiproot_false_routes_via_root():
+    configure_logging(skiproot=False)
+    for name in ("kanta.bootstrap", "kanta.migration", "kanta.transaction"):
+        logger = logging.getLogger(name)
+        assert logger.propagate
+        assert not logger.handlers
+
+
+def _setup_logging(**kwargs):
+    """Default kanta logging with the event loggers lifted to INFO.
+
+    Event loggers inherit the root level (WARNING under pytest); output
+    assertions need INFO.
+    """
+    configure_logging(**kwargs)
+    for name in ("kanta.bootstrap", "kanta.migration", "kanta.transaction"):
+        logging.getLogger(name).setLevel(logging.INFO)


 def test_log_change_no_diff(capsys):
-    kanta_logger = logging.getLogger("kanta")
-    kanta_logger.handlers.clear()
-    configure_logging()
+    _setup_logging()
    log_change("test", {})
    captured = capsys.readouterr()
    assert "test" in captured.err
@@ -74,9 +83,7 @@ def test_log_change_no_diff(capsys):
 def test_log_change_appends_extra_string(capsys, monkeypatch):
    monkeypatch.setenv("FORCE_COLOR", "1")
    monkeypatch.delenv("NO_COLOR", raising=False)
-    kanta_logger = logging.getLogger("kanta")
-    kanta_logger.handlers.clear()
-    configure_logging()
+    _setup_logging()
    log_change("export", {}, extra="mydb.db")
    captured = capsys.readouterr()
    assert "export" in captured.err
@@ -84,9 +91,7 @@ def test_log_change_appends_extra_string(capsys, monkeypatch):


 def test_log_change_log_diff_false(capsys, monkeypatch):
-    kanta_logger = logging.getLogger("kanta")
-    kanta_logger.handlers.clear()
-    configure_logging()
+    _setup_logging()

    def _boom(*args, **kwargs):
        raise AssertionError("format_diff should not be called")
@@ -99,9 +104,7 @@ def test_log_change_log_diff_false(capsys, monkeypatch):


 def test_configure_logging_diff_false(capsys):
-    kanta_logger = logging.getLogger("kanta")
-    kanta_logger.handlers.clear()
-    configure_logging(diff=False)
+    _setup_logging(diff=False)
    log_change("update", {"counter": 5}, previous={})
    captured = capsys.readouterr()
    assert "update" in captured.err
@@ -109,10 +112,9 @@ def test_configure_logging_diff_false(capsys):


 def test_configure_logging_diff_true_reenables(capsys):
-    kanta_logger = logging.getLogger("kanta")
-    kanta_logger.handlers.clear()
-    configure_logging(diff=False)
+    _setup_logging(diff=False)
    configure_logging(diff=True)
+    logging.getLogger("kanta.transaction").setLevel(logging.INFO)
    log_change("update", {"counter": 5}, previous={})
    captured = capsys.readouterr()
    assert "counter" in captured.err