diff --git a/kanta/kanta.py b/kanta/kanta.py index 80c425a..963f308 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -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. diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index 11a8b16..ea6495a 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -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 diff --git a/kanta/logging.py b/kanta/logging.py index bf67234..b4ed8f4 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -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) diff --git a/kanta/transaction.py b/kanta/transaction.py index 9d2886d..80b4803 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -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, diff --git a/tests/test_callbacks.py b/tests/test_callbacks.py index ffac1b7..32b0d2a 100644 --- a/tests/test_callbacks.py +++ b/tests/test_callbacks.py @@ -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) diff --git a/tests/test_kanta_integration.py b/tests/test_kanta_integration.py index 01fad01..94f97ba 100644 --- a/tests/test_kanta_integration.py +++ b/tests/test_kanta_integration.py @@ -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 diff --git a/tests/test_logging.py b/tests/test_logging.py index 7e8b691..739c3d5 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -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()