diff --git a/docs/database.md b/docs/database.md index 07673ec..ec93c8b 100644 --- a/docs/database.md +++ b/docs/database.md @@ -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 diff --git a/kanta/logging.py b/kanta/logging.py index 8ae7f7b..5a01014 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -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. diff --git a/tests/conftest.py b/tests/conftest.py index f4e37f0..c1d7e85 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -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 diff --git a/tests/test_logemit.py b/tests/test_logemit.py index 84a14ac..a5dd00b 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -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}" diff --git a/tests/test_logging.py b/tests/test_logging.py index 5582118..13b2e18 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -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