Add kanta.bootstrap logger and configurable logging setup

- Bootstrap records are now logged via kanta.bootstrap at INFO level. - Existing databases log 'Using <path>' at DEBUG on kanta.bootstrap. - New databases log 'Created <path>' at INFO on kanta.bootstrap. - Renamed loggers: kanta.changes -> kanta.transaction, kanta.migrations -> kanta.migration. - configure_logging() gains bootstrap/migration/transaction/skiproot kwargs. - Default configure_logging() attaches a no-prefix stderr handler to kanta and stops propagation. - With skiproot=False, child logger propagation flags are still applied but kanta itself is left untouched. - Updated tests and docstrings.
2026-06-20 19:10:58 +00:00
parent 3e1a86aee3
commit 9c0b47ce38
7 changed files with 129 additions and 38 deletions
@@ -164,8 +164,8 @@ class Kanta(Generic[T]):
                no background flush task is started, and transactions are
                rejected. The file is not created if missing.
            log: Controls bootstrap and migration logging. ``True`` (default)
-                uses the ``kanta.changes`` logger for bootstrap records and the
-                ``kanta.migrations`` logger for migration output. ``False``
+                uses the ``kanta.bootstrap`` logger for bootstrap records and
+                the ``kanta.migration`` logger for migration output. ``False``
                suppresses the default bootstrap and migration logs. A
                :class:`~logging.Logger` instance writes default output to that
                logger instead. Custom ``@kanta.logmigr`` callbacks run
@@ -314,9 +314,9 @@ class Kanta(Generic[T]):
                :class:`~datetime.datetime` value sets ``m`` to that explicit
                time.
            log: Controls transaction logging. ``True`` (default) uses the
-                ``kanta.changes`` logger. ``False`` suppresses the transaction
-                log. A :class:`~logging.Logger` instance writes output to that
-                logger instead.
+                ``kanta.transaction`` logger. ``False`` suppresses the
+                transaction log. A :class:`~logging.Logger` instance writes
+                output to that logger instead.

        Returns:
            A context manager yielding the live state object for mutation.
@@ -12,7 +12,7 @@ from typing import Any, Generic, TypeVar

 from kanta.callbacks import CallbackRegistry, InjectionContext
 from kanta.exceptions import DatabaseError, DataIntegrityError, ReplayError
-from kanta.logging import _USER_PATH, changes_logger, log_change, migration_logger
+from kanta.logging import _USER_PATH, bootstrap_logger, log_change, migration_logger
 from kanta.migrations import MigrationResult, Migrations
 from kanta.persistence import PersistenceMixin
 from kanta.serialization import restore_data_in_place, struct_to_dict
@@ -235,6 +235,9 @@ class KantaImpl(PersistenceMixin, Generic[T]):
            )
            self.version = rr.version
            self.mtime = rr.m
+            if log is not False:
+                logger = log if isinstance(log, logging.Logger) else bootstrap_logger
+                logger.debug("Using %s", self.filename.resolve())
            normalized = struct_to_dict(self.data, serializer=self.serializer)
            if self.readonly:
                self.statedict = copy.deepcopy(normalized)
@@ -286,7 +289,7 @@ class KantaImpl(PersistenceMixin, Generic[T]):
                )

                if record is not None and log is not False:
-                    logger = log if isinstance(log, logging.Logger) else changes_logger
+                    logger = log if isinstance(log, logging.Logger) else bootstrap_logger
                    logger.info("Created %s", self.filename.resolve())
                    logfmt = self.callback_registry.build_logfmt(
                        InjectionContext(
@@ -307,6 +310,7 @@ class KantaImpl(PersistenceMixin, Generic[T]):
                        previous={},
                        logfmt=logfmt,
                        logger=logger,
+                        level=logging.INFO,
                    )
            except Exception:
                self.opened = False
@@ -1,7 +1,8 @@
 """Database change logging with pretty-printed diffs.

-Provides a logger for JSONL database changes that formats diffs
-in a human-readable path.notation style with color coding.
+Provides loggers for JSONL database changes, bootstrap events, and
+migrations.  Diff output is formatted in a human-readable path notation
+style with color coding.
 """

 import logging
@@ -10,8 +11,9 @@ import sys
 from collections.abc import Callable
 from typing import Any

-changes_logger = logging.getLogger("kanta.changes")
-migration_logger = logging.getLogger("kanta.migrations")
+transaction_logger = logging.getLogger("kanta.transaction")
+bootstrap_logger = logging.getLogger("kanta.bootstrap")
+migration_logger = logging.getLogger("kanta.migration")

 # Pattern to match control characters and bidirectional overrides
 _UNSAFE_CHARS = re.compile(
@@ -276,7 +278,7 @@ def log_change(
    previous: dict | None = None,
    logfmt: Callable[[Any, str], str | None] | None = None,
    *,
-    logger: logging.Logger = changes_logger,
+    logger: logging.Logger = transaction_logger,
    level: int = logging.INFO,
 ) -> None:
    """Log a database change with pretty-printed diff.
@@ -287,7 +289,7 @@ def log_change(
        user: Optional already-formatted user name to show in the header.
        previous: The previous state dict (for determining add vs update).
        logfmt: Optional formatter callable ``(value, path) -> str | None``.
-        logger: Logger to write to. Defaults to the ``kanta.changes`` logger.
+        logger: Logger to write to. Defaults to the ``kanta.transaction`` logger.
        level: Log level to use. Defaults to ``logging.INFO``.
    """
    header = format_action_header(action, user)
@@ -305,11 +307,45 @@ def log_change(
            logger.log(level, line)


-def configure_logging() -> None:
-    """Configure the database logger to output to stderr without prefix."""
-    if not changes_logger.handlers:
+def configure_logging(
+    *,
+    skiproot: bool = True,
+    bootstrap: bool = True,
+    migration: bool = True,
+    transaction: bool = True,
+) -> None:
+    """Configure Kanta's default logging output.
+
+    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.
+        bootstrap: Whether bootstrap logs are enabled.
+        migration: Whether migration logs are enabled.
+        transaction: Whether transaction logs are enabled.
+
+    This helper is not called automatically; applications that want Kanta's
+    default output can call it, but most applications will configure logging
+    themselves.
+    """
+    for name, enabled in (
+        ("kanta.bootstrap", bootstrap),
+        ("kanta.migration", migration),
+        ("kanta.transaction", transaction),
+    ):
+        logging.getLogger(name).propagate = enabled
+
+    if not skiproot:
+        return
+
+    target = logging.getLogger("kanta")
+    target.propagate = False
+
+    if not target.handlers:
        handler = logging.StreamHandler(sys.stderr)
        handler.setFormatter(logging.Formatter("%(message)s"))
-        changes_logger.addHandler(handler)
-    changes_logger.setLevel(logging.INFO)
-    changes_logger.propagate = False
+        target.addHandler(handler)
+    target.setLevel(logging.INFO)
@@ -9,7 +9,7 @@ from datetime import datetime
 from kanta.diff import compute_diff
 from kanta.exceptions import DataIntegrityError
 from kanta.callbacks import InjectionContext
-from kanta.logging import _USER_PATH, changes_logger, log_change
+from kanta.logging import _USER_PATH, log_change, transaction_logger
 from kanta.serialization import restore_data_in_place, struct_to_dict

 _logger = logging.getLogger(__name__)
@@ -82,7 +82,7 @@ def transaction(
                    if resolved is not None:
                        formatted_user = resolved
                if log is not False:
-                    logger = log if isinstance(log, logging.Logger) else changes_logger
+                    logger = log if isinstance(log, logging.Logger) else transaction_logger
                    log_change(
                        action,
                        record.diff,
@@ -148,7 +148,7 @@ async def test_bootstrap_injects_kanta(tmp_path, format_config):
 async def test_logfmt_injects_states(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -170,7 +170,7 @@ async def test_logfmt_injects_states(tmp_path, format_config, caplog):
 async def test_logfmt_class_injection(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -195,7 +195,7 @@ async def test_logfmt_class_injection(tmp_path, format_config, caplog):
 async def test_multiple_logfmt_chain(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -223,7 +223,7 @@ async def test_multiple_logfmt_chain(tmp_path, format_config, caplog):
 async def test_logfmt_path_context(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -247,7 +247,7 @@ async def test_logfmt_path_context(tmp_path, format_config, caplog):
 async def test_logfmt_decorator_path_filters_calls(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -273,7 +273,7 @@ async def test_logfmt_decorator_path_filters_calls(tmp_path, format_config, capl
 async def test_logfmt_user_path_replaces_user_display(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -295,7 +295,7 @@ async def test_logfmt_user_path_replaces_user_display(tmp_path, format_config, c
 async def test_logfmt_non_string_value(tmp_path, format_config, caplog):
    import logging

-    caplog.set_level(logging.INFO, logger="kanta.changes")
+    caplog.set_level(logging.INFO, logger="kanta.transaction")
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

@@ -589,7 +589,7 @@ async def test_migration_summary_log_includes_filename(tmp_path, format_config,

    mod.__dict__["migrate_v1"] = migrate_v1

-    with caplog.at_level(logging.INFO, logger="kanta.migrations"):
+    with caplog.at_level(logging.INFO, logger="kanta.migration"):
        kanta = make_kanta(path, Data, format_config, migrations=mod)
        await kanta.open()
        assert kanta.version == 1
@@ -614,7 +614,7 @@ async def test_open_log_false_suppresses_migration_log(tmp_path, format_config,

    mod.__dict__["migrate_v1"] = migrate_v1

-    with caplog.at_level(logging.INFO, logger="kanta.migrations"):
+    with caplog.at_level(logging.INFO, logger="kanta.migration"):
        kanta = make_kanta(path, Data, format_config, migrations=mod)
        await kanta.open(log=False)
        await kanta.close()
@@ -628,7 +628,7 @@ async def test_open_log_true_logs_bootstrap(tmp_path, format_config, caplog):
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

-    with caplog.at_level(logging.INFO, logger="kanta.changes"):
+    with caplog.at_level(logging.INFO, logger="kanta.bootstrap"):
        await kanta.open()
        await kanta.close()

@@ -643,7 +643,7 @@ async def test_open_log_false_suppresses_bootstrap_log(tmp_path, format_config,
    path = tmp_path / "test.db"
    kanta = make_kanta(path, Data, format_config)

-    with caplog.at_level(logging.INFO, logger="kanta.changes"):
+    with caplog.at_level(logging.INFO, logger="kanta.bootstrap"):
        await kanta.open(log=False)
        await kanta.close()

@@ -669,6 +669,25 @@ async def test_open_log_custom_logger_logs_bootstrap(tmp_path, format_config, ca
    assert "bootstrap" in info_messages[1]


+@pytest.mark.asyncio
+async def test_open_existing_database_logs_using_on_debug(
+    tmp_path, format_config, caplog
+):
+    path = tmp_path / "test.db"
+    kanta = make_kanta(path, Data, format_config)
+    await kanta.open()
+    await kanta.close()
+
+    kanta2 = make_kanta(path, Data, format_config)
+
+    with caplog.at_level(logging.DEBUG, logger="kanta.bootstrap"):
+        await kanta2.open()
+        await kanta2.close()
+
+    debug_messages = [r.message for r in caplog.records if r.levelno == logging.DEBUG]
+    assert any("Using" in m and str(path.resolve()) in m for m in debug_messages)
+
+
@pytest.mark.asyncio
 async def test_logmigr_callback_replaces_default_logging(
    tmp_path, format_config, caplog
@@ -692,7 +711,7 @@ async def test_logmigr_callback_replaces_default_logging(
    def collect(summary: MigrationResult):
        summaries.append(summary)

-    with caplog.at_level(logging.INFO, logger="kanta.migrations"):
+    with caplog.at_level(logging.INFO, logger="kanta.migration"):
        await kanta.open()
        await kanta.close()

@@ -709,7 +728,7 @@ async def test_transaction_log_false_suppresses_log(tmp_path, format_config, cap
    kanta = make_kanta(path, Data, format_config)
    await kanta.open()

-    with caplog.at_level(logging.INFO, logger="kanta.changes"):
+    with caplog.at_level(logging.INFO, logger="kanta.transaction"):
        with kanta.transaction(action="inc", log=False) as data:
            data.counter = 1

@@ -1,15 +1,47 @@
 import logging

-from kanta.logging import changes_logger, configure_logging, log_change
+import pytest
+
+from kanta.logging import configure_logging, log_change, transaction_logger


-def test_configure_logging():
+@pytest.fixture(autouse=True)
+def _reset_kanta_loggers():
+    yield
+    for name in ("kanta", "kanta.transaction", "kanta.bootstrap", "kanta.migration"):
+        logger = logging.getLogger(name)
+        logger.setLevel(logging.NOTSET)
+        logger.propagate = True
+        logger.handlers.clear()
+
+
+def test_configure_logging_defaults():
+    kanta_logger = logging.getLogger("kanta")
    configure_logging()
-    assert changes_logger.level == logging.INFO
+    assert kanta_logger.level == logging.INFO
+    assert not kanta_logger.propagate
+    assert kanta_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
+
+
+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_log_change_no_diff(capsys):
-    changes_logger.handlers.clear()
+    kanta_logger = logging.getLogger("kanta")
+    kanta_logger.handlers.clear()
    configure_logging()
    log_change("test", {})
    captured = capsys.readouterr()