2 Commits
Author SHA1 Message Date
LeoVasanko 3a56bfbb10 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
LeoVasanko 55fa475a13 Log new database creation, bootstrap like a transaction. 2026-06-20 18:15:08 +00:00
7 changed files with 204 additions and 39 deletions
+10 -8
View File
@@ -163,11 +163,13 @@ class Kanta(Generic[T]):
readonly: If True, open the database read-only. No lock is acquired, readonly: If True, open the database read-only. No lock is acquired,
no background flush task is started, and transactions are no background flush task is started, and transactions are
rejected. The file is not created if missing. rejected. The file is not created if missing.
log: Controls migration logging. ``True`` (default) uses the log: Controls bootstrap and migration logging. ``True`` (default)
``kanta.migrations`` logger. ``False`` suppresses the default uses the ``kanta.bootstrap`` logger for bootstrap records and
migration log. A :class:`~logging.Logger` instance writes the ``kanta.migration`` logger for migration output. ``False``
default migration output to that logger instead. Custom suppresses the default bootstrap and migration logs. A
``@kanta.logmigr`` callbacks run regardless of this setting. :class:`~logging.Logger` instance writes default output to that
logger instead. Custom ``@kanta.logmigr`` callbacks run
regardless of this setting.
Calling ``open`` more than once on the same instance is not allowed. Calling ``open`` more than once on the same instance is not allowed.
@@ -312,9 +314,9 @@ class Kanta(Generic[T]):
:class:`~datetime.datetime` value sets ``m`` to that explicit :class:`~datetime.datetime` value sets ``m`` to that explicit
time. time.
log: Controls transaction logging. ``True`` (default) uses the log: Controls transaction logging. ``True`` (default) uses the
``kanta.changes`` logger. ``False`` suppresses the transaction ``kanta.transaction`` logger. ``False`` suppresses the
log. A :class:`~logging.Logger` instance writes output to that transaction log. A :class:`~logging.Logger` instance writes
logger instead. output to that logger instead.
Returns: Returns:
A context manager yielding the live state object for mutation. A context manager yielding the live state object for mutation.
+30 -2
View File
@@ -12,7 +12,7 @@ from typing import Any, Generic, TypeVar
from kanta.callbacks import CallbackRegistry, InjectionContext from kanta.callbacks import CallbackRegistry, InjectionContext
from kanta.exceptions import DatabaseError, DataIntegrityError, ReplayError from kanta.exceptions import DatabaseError, DataIntegrityError, ReplayError
from kanta.logging import log_change, migration_logger from kanta.logging import _USER_PATH, bootstrap_logger, log_change, migration_logger
from kanta.migrations import MigrationResult, Migrations from kanta.migrations import MigrationResult, Migrations
from kanta.persistence import PersistenceMixin from kanta.persistence import PersistenceMixin
from kanta.serialization import restore_data_in_place, struct_to_dict 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.version = rr.version
self.mtime = rr.m 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) normalized = struct_to_dict(self.data, serializer=self.serializer)
if self.readonly: if self.readonly:
self.statedict = copy.deepcopy(normalized) self.statedict = copy.deepcopy(normalized)
@@ -277,13 +280,38 @@ class KantaImpl(PersistenceMixin, Generic[T]):
self.statedict = {} self.statedict = {}
current = struct_to_dict(self.data, serializer=self.serializer) current = struct_to_dict(self.data, serializer=self.serializer)
self.queue_change( record = self.queue_change(
self.bootstrap_action, self.bootstrap_action,
current, current,
user=self.bootstrap_user, user=self.bootstrap_user,
mtime=self.bootstrap_mtime, mtime=self.bootstrap_mtime,
force=True, force=True,
) )
if record is not None and log is not False:
logger = log if isinstance(log, logging.Logger) else bootstrap_logger
logger.info("Created %s", self.filename.resolve())
logfmt = self.callback_registry.build_logfmt(
InjectionContext(
previous_state={},
current_state=current,
kanta=self._kanta,
)
)
formatted_user = self.bootstrap_user
if formatted_user is not None and logfmt is not None:
resolved = logfmt(formatted_user, _USER_PATH)
if resolved is not None:
formatted_user = resolved
log_change(
self.bootstrap_action,
record.diff,
formatted_user,
previous={},
logfmt=logfmt,
logger=logger,
level=logging.INFO,
)
except Exception: except Exception:
self.opened = False self.opened = False
self.file.close() self.file.close()
+48 -12
View File
@@ -1,7 +1,8 @@
"""Database change logging with pretty-printed diffs. """Database change logging with pretty-printed diffs.
Provides a logger for JSONL database changes that formats diffs Provides loggers for JSONL database changes, bootstrap events, and
in a human-readable path.notation style with color coding. migrations. Diff output is formatted in a human-readable path notation
style with color coding.
""" """
import logging import logging
@@ -10,8 +11,9 @@ import sys
from collections.abc import Callable from collections.abc import Callable
from typing import Any from typing import Any
changes_logger = logging.getLogger("kanta.changes") transaction_logger = logging.getLogger("kanta.transaction")
migration_logger = logging.getLogger("kanta.migrations") bootstrap_logger = logging.getLogger("kanta.bootstrap")
migration_logger = logging.getLogger("kanta.migration")
# Pattern to match control characters and bidirectional overrides # Pattern to match control characters and bidirectional overrides
_UNSAFE_CHARS = re.compile( _UNSAFE_CHARS = re.compile(
@@ -276,7 +278,7 @@ def log_change(
previous: dict | None = None, previous: dict | None = None,
logfmt: Callable[[Any, str], str | None] | None = None, logfmt: Callable[[Any, str], str | None] | None = None,
*, *,
logger: logging.Logger = changes_logger, logger: logging.Logger = transaction_logger,
level: int = logging.INFO, level: int = logging.INFO,
) -> None: ) -> None:
"""Log a database change with pretty-printed diff. """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. user: Optional already-formatted user name to show in the header.
previous: The previous state dict (for determining add vs update). previous: The previous state dict (for determining add vs update).
logfmt: Optional formatter callable ``(value, path) -> str | None``. 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``. level: Log level to use. Defaults to ``logging.INFO``.
""" """
header = format_action_header(action, user) header = format_action_header(action, user)
@@ -305,11 +307,45 @@ def log_change(
logger.log(level, line) logger.log(level, line)
def configure_logging() -> None: def configure_logging(
"""Configure the database logger to output to stderr without prefix.""" *,
if not changes_logger.handlers: 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 = logging.StreamHandler(sys.stderr)
handler.setFormatter(logging.Formatter("%(message)s")) handler.setFormatter(logging.Formatter("%(message)s"))
changes_logger.addHandler(handler) target.addHandler(handler)
changes_logger.setLevel(logging.INFO) target.setLevel(logging.INFO)
changes_logger.propagate = False
+2 -2
View File
@@ -9,7 +9,7 @@ from datetime import datetime
from kanta.diff import compute_diff from kanta.diff import compute_diff
from kanta.exceptions import DataIntegrityError from kanta.exceptions import DataIntegrityError
from kanta.callbacks import InjectionContext 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 from kanta.serialization import restore_data_in_place, struct_to_dict
_logger = logging.getLogger(__name__) _logger = logging.getLogger(__name__)
@@ -82,7 +82,7 @@ def transaction(
if resolved is not None: if resolved is not None:
formatted_user = resolved formatted_user = resolved
if log is not False: 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( log_change(
action, action,
record.diff, record.diff,
+9 -7
View File
@@ -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): async def test_logfmt_injects_states(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
@@ -170,13 +170,15 @@ async def test_logfmt_injects_states(tmp_path, format_config, caplog):
async def test_logfmt_class_injection(tmp_path, format_config, caplog): async def test_logfmt_class_injection(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
@kanta.logfmt @kanta.logfmt
class UserLogFmt(LogFmt): class UserLogFmt(LogFmt):
def resolve(self, value: str, path: str) -> str | None: def resolve(self, value: str, path: str) -> str | None:
if not isinstance(value, str):
return None
return self.current_state.get("users", {}).get(value, {}).get("name") return self.current_state.get("users", {}).get(value, {}).get("name")
await kanta.open() await kanta.open()
@@ -193,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): async def test_multiple_logfmt_chain(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
@@ -221,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): async def test_logfmt_path_context(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
@@ -245,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): async def test_logfmt_decorator_path_filters_calls(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
@@ -271,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): async def test_logfmt_user_path_replaces_user_display(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
@@ -293,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): async def test_logfmt_non_string_value(tmp_path, format_config, caplog):
import logging import logging
caplog.set_level(logging.INFO, logger="kanta.changes") caplog.set_level(logging.INFO, logger="kanta.transaction")
path = tmp_path / "test.db" path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
+69 -4
View File
@@ -589,7 +589,7 @@ async def test_migration_summary_log_includes_filename(tmp_path, format_config,
mod.__dict__["migrate_v1"] = migrate_v1 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) kanta = make_kanta(path, Data, format_config, migrations=mod)
await kanta.open() await kanta.open()
assert kanta.version == 1 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 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) kanta = make_kanta(path, Data, format_config, migrations=mod)
await kanta.open(log=False) await kanta.open(log=False)
await kanta.close() await kanta.close()
@@ -623,6 +623,71 @@ async def test_open_log_false_suppresses_migration_log(tmp_path, format_config,
assert not info_messages assert not info_messages
@pytest.mark.asyncio
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.bootstrap"):
await kanta.open()
await kanta.close()
info_messages = [r.message for r in caplog.records if r.levelno == logging.INFO]
assert len(info_messages) >= 2
assert "Created" in info_messages[0]
assert "bootstrap" in info_messages[1]
@pytest.mark.asyncio
async def test_open_log_false_suppresses_bootstrap_log(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.bootstrap"):
await kanta.open(log=False)
await kanta.close()
info_messages = [r for r in caplog.records if r.levelno == logging.INFO]
assert not info_messages
@pytest.mark.asyncio
async def test_open_log_custom_logger_logs_bootstrap(tmp_path, format_config, caplog):
path = tmp_path / "test.db"
kanta = make_kanta(path, Data, format_config)
custom_logger = logging.getLogger("custom.bootstrap")
custom_logger.setLevel(logging.INFO)
with caplog.at_level(logging.INFO, logger="custom.bootstrap"):
await kanta.open(log=custom_logger)
await kanta.close()
info_messages = [r.message for r in caplog.records if r.levelno == logging.INFO]
assert len(info_messages) >= 2
assert "Created" in info_messages[0]
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 @pytest.mark.asyncio
async def test_logmigr_callback_replaces_default_logging( async def test_logmigr_callback_replaces_default_logging(
tmp_path, format_config, caplog tmp_path, format_config, caplog
@@ -646,7 +711,7 @@ async def test_logmigr_callback_replaces_default_logging(
def collect(summary: MigrationResult): def collect(summary: MigrationResult):
summaries.append(summary) 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.open()
await kanta.close() await kanta.close()
@@ -663,7 +728,7 @@ async def test_transaction_log_false_suppresses_log(tmp_path, format_config, cap
kanta = make_kanta(path, Data, format_config) kanta = make_kanta(path, Data, format_config)
await kanta.open() 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: with kanta.transaction(action="inc", log=False) as data:
data.counter = 1 data.counter = 1
+36 -4
View File
@@ -1,15 +1,47 @@
import logging 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() 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): def test_log_change_no_diff(capsys):
changes_logger.handlers.clear() kanta_logger = logging.getLogger("kanta")
kanta_logger.handlers.clear()
configure_logging() configure_logging()
log_change("test", {}) log_change("test", {})
captured = capsys.readouterr() captured = capsys.readouterr()