From 1e9f83c8005bdbeb491d752600674bc000e5800e Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:03:24 +0000 Subject: [PATCH 01/24] Add rich transaction log headers: extra metadata, logheader callback, header/diff toggles, green add paths --- kanta/callbacks.py | 74 +++++++++++++++++++++++++++++++++++++++++--- kanta/kanta.py | 39 +++++++++++++++++++++-- kanta/kantaimpl.py | 46 +++++++++++++++++++++++++++ kanta/logging.py | 59 +++++++++++++++++++++++++++++------ kanta/transaction.py | 23 ++++++++++++-- 5 files changed, 220 insertions(+), 21 deletions(-) diff --git a/kanta/callbacks.py b/kanta/callbacks.py index ef82271..0d83362 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -61,6 +61,9 @@ class InjectionContext: previous_state: dict | None = None current_state: dict | None = None migration_result: MigrationResult | None = None + action: str | None = None + user: str | None = None + extra: Any = None @dataclass @@ -101,6 +104,7 @@ class CallbackRegistry: "bootstrap": [], "fatal_error": [], "logmigr": [], + "logheader": [], } self._logfmt_callbacks: list[_LogFmtFunctionSpec | _LogFmtClassSpec] = [] @@ -131,6 +135,18 @@ class CallbackRegistry: if not callable(callback): raise TypeError(f"{kind} callback must be callable") + if kind == "logheader": + if inspect.iscoroutinefunction(callback): + raise TypeError("logheader callbacks must not be async") + return_ann = inspect.signature(callback).return_annotation + if return_ann is not inspect.Signature.empty: + resolved = self._resolve_raw_annotation(return_ann, callback) + if not self._is_optional_str(resolved): + raise TypeError( + f"logheader callback {callback.__name__} must return " + f"str | None, got {resolved!r}" + ) + params = self._validate_function(callback, kind) is_async = inspect.iscoroutinefunction(callback) @@ -217,6 +233,27 @@ class CallbackRegistry: return format_value + def resolve_logheader(self, ctx: InjectionContext) -> str | None: + """Invoke logheader callbacks; the first non-None result wins.""" + for reg in self._callbacks["logheader"]: + kwargs = self._build_kwargs(reg.params, ctx) + result = reg.callback(**kwargs) + if result is not None: + return result + return None + + @staticmethod + def _logheader_param_annotation(name: str, ann: Any) -> Any: + """Map logheader parameter names to their injection sentinels.""" + bare = CallbackRegistry._unwrap_optional(ann) + if name == "action" and bare is str: + return _HeaderAction + if name == "user" and bare is str: + return _HeaderUser + if name == "extra" and (bare is dict or get_origin(bare) is dict): + return _HeaderExtra + return None + def _validate_function( self, callback: Callable[..., Any], @@ -240,6 +277,11 @@ class CallbackRegistry: continue ann = self._resolve_raw_annotation(param.annotation, callback) + if kind == "logheader": + header_ann = self._logheader_param_annotation(name, ann) + if header_ann is not None: + params.append((name, header_ann)) + continue if not self._is_allowed(kind, ann): if param.default is inspect.Parameter.empty: raise TypeError( @@ -444,9 +486,9 @@ class CallbackRegistry: def _is_allowed(self, kind: str, ann: Any) -> bool: bare = self._unwrap_optional(ann) if self._matches_state_annotation(bare, "pre"): - return kind == "logfmt" + return kind in {"logfmt", "logheader"} if self._matches_state_annotation(bare, "post"): - return kind == "logfmt" + return kind in {"logfmt", "logheader"} if bare is DatabaseError: return kind == "fatal_error" if bare is MigrationResult: @@ -454,7 +496,7 @@ class CallbackRegistry: if self._data_type is not None and bare is self._data_type: return kind == "bootstrap" if self._kanta_class is not None and bare is self._kanta_class: - return kind in {"bootstrap", "fatal_error", "logfmt", "logmigr"} + return kind in {"bootstrap", "fatal_error", "logfmt", "logmigr", "logheader"} return False def _allowed_message(self, kind: str) -> str: @@ -462,19 +504,29 @@ class CallbackRegistry: if kind == "bootstrap": if self._data_type is not None: parts.append(self._data_type.__name__) - if kind in {"bootstrap", "fatal_error", "logfmt"}: + if kind in {"bootstrap", "fatal_error", "logfmt", "logmigr", "logheader"}: if self._kanta_class is not None: parts.append(self._kanta_class.__name__) if kind == "fatal_error": parts.append("DatabaseError") if kind == "logmigr": parts.append("MigrationResult") - if kind == "logfmt": + if kind == "logheader": + parts.append("action: str") + parts.append("user: str | None") + parts.append("extra: dict | None") + if kind in {"logfmt", "logheader"}: parts.append("Annotated[dict, 'pre']") parts.append("Annotated[dict, 'post']") return ", ".join(parts) if parts else "none" def _resolve_annotation(self, ann: Any, ctx: InjectionContext) -> Any: + if ann is _HeaderAction: + return ctx.action + if ann is _HeaderUser: + return ctx.user + if ann is _HeaderExtra: + return ctx.extra bare = self._unwrap_optional(ann) if self._matches_state_annotation(bare, "pre"): return ctx.previous_state @@ -532,6 +584,18 @@ class CallbackRegistry: return type(None) in args and any(arg is str for arg in args) +class _HeaderAction: + """Sentinel annotation injecting the transaction action.""" + + +class _HeaderUser: + """Sentinel annotation injecting the transaction user.""" + + +class _HeaderExtra: + """Sentinel annotation injecting the display-only extra metadata.""" + + class _Unresolved: pass diff --git a/kanta/kanta.py b/kanta/kanta.py index 963f308..93eb19b 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -5,7 +5,7 @@ import logging from datetime import datetime from pathlib import Path from types import ModuleType, SimpleNamespace -from typing import Generic, TypeVar +from typing import Any, Generic, TypeVar from kanta.kantaimpl import KantaImpl from kanta.serialization import JsonSerializer, Serializer @@ -292,13 +292,38 @@ class Kanta(Generic[T]): return _register return _register(fn) + def logheader(self, fn=None): + """Register a transaction log header callback. + + Can be used as ``@kanta.logheader``. The callback formats the entire + header line printed before a transaction diff. It may declare + ``action: str``, ``user: str | None`` and ``extra: dict | None`` + parameters, and can also have ``DictPre``/``DictPost`` state dicts and + the ``Kanta`` instance injected. It must return ``str`` (or ``None`` + to fall through to the next callback, then to the default header). + + If registered, this replaces the default ``action by user`` header. + The ``extra`` metadata passed to :meth:`transaction` is display-only + and is never persisted; when no ``target`` key is supplied it defaults + to the database filename. + """ + + def _register(callback): + self._impl.add_logheader(callback) + return callback + + if fn is None: + return _register + return _register(fn) + def transaction( self, action: str, *, user: str | None = None, + extra: str | dict[str, Any] | None = None, mtime: bool | datetime = True, - log: bool | logging.Logger = True, + log: bool | logging.Logger | dict[str, bool] = True, ): """Create a transactional mutation context manager. @@ -307,6 +332,11 @@ class Kanta(Generic[T]): user: Optional user identifier stored in metadata and rendered in the log header. Register a ``@kanta.logfmt`` callback to format the user value; the path ``"$user"`` is passed for this case. + extra: Optional display-only metadata used for logging; it is not + persisted in the change record. A string is appended after + the action in the default header. A dict is passed to a + registered ``@kanta.logheader`` callback; if it has no + ``"target"`` key, the database filename is used. mtime: Controls the modification time ``m``. ``True`` (default) sets ``m`` to the current UTC time. ``False`` omits ``m`` so the previous modification time remains in effect; this is used for @@ -316,7 +346,9 @@ class Kanta(Generic[T]): log: Controls transaction logging. ``True`` (default) uses the ``kanta.transaction`` logger. ``False`` suppresses the transaction log. A :class:`~logging.Logger` instance writes - output to that logger instead. + output to that logger instead. A dict such as + ``{"header": True, "diff": False}`` toggles the header and + diff parts independently. Returns: A context manager yielding the live state object for mutation. @@ -330,6 +362,7 @@ class Kanta(Generic[T]): self._impl, action, user=user, + extra=extra, mtime=mtime, log=log, ) diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index ea6495a..f2dfeda 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -6,6 +6,7 @@ import asyncio import copy import importlib import logging +from collections.abc import Callable from datetime import UTC, datetime from types import SimpleNamespace from typing import Any, Generic, TypeVar @@ -80,6 +81,46 @@ class KantaImpl(PersistenceMixin, Generic[T]): """Register one migration logging callback.""" self.callback_registry.register("logmigr", callback) + def add_logheader(self, callback) -> None: + """Register one transaction header formatting callback.""" + self.callback_registry.register("logheader", callback) + + def build_headerfmt( + self, + action: str, + user: str | None, + extra: str | dict[str, Any] | None, + previous: dict | None, + current: dict | None, + ) -> tuple[Callable[..., str | None] | None, str | dict[str, Any] | None]: + """Build a headerfmt callable and normalized extra for ``log_change``. + + Returns ``(None, extra)`` unchanged when no logheader callback is + registered. Otherwise the extra dict gets a default ``target`` (the + database filename) when not supplied, so single-database apps get a + useful header with no extra code. + """ + if not self.callback_registry.has("logheader"): + return None, extra + if extra is None: + extra = {} + if isinstance(extra, dict) and "target" not in extra: + extra = {**extra, "target": self.filename.name} + ctx = InjectionContext( + action=action, + user=user, + extra=extra, + previous_state=previous, + current_state=current, + kanta=self._kanta, + ) + registry = self.callback_registry + + def headerfmt(action: str, user: str | None, extra: Any) -> str | None: + return registry.resolve_logheader(ctx) + + return headerfmt, extra + async def _handle_migration_log( self, migration_result: MigrationResult, @@ -303,12 +344,17 @@ class KantaImpl(PersistenceMixin, Generic[T]): resolved = logfmt(formatted_user, _USER_PATH) if resolved is not None: formatted_user = resolved + headerfmt, extra = self.build_headerfmt( + self.bootstrap_action, formatted_user, None, {}, current + ) log_change( self.bootstrap_action, record.diff, formatted_user, previous={}, + extra=extra, logfmt=logfmt, + headerfmt=headerfmt, logger=logger, level=logging.INFO, ) diff --git a/kanta/logging.py b/kanta/logging.py index b4ed8f4..38d9b59 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -33,6 +33,9 @@ _DELETE = "\033[1;31m" # Red for deletions _ADD = "\033[0;32m" # Green for additions _ACTION = "\033[1;34m" # Bold blue for action name _USER = "\033[0;34m" # Blue for user display +_ACTOR = "\033[0;36m" # Cyan for actor/label header fields +_SESSION = "\033[38;5;226m" # Bright yellow for session/request ids +_TARGET = "\033[38;5;250m" # White for target object names/ids # Metadata path used when formatting the transaction actor. _USER_PATH = "$user" @@ -116,17 +119,19 @@ def _format_path_components( def _format_path( - path: list[str], logfmt: Callable[[Any, str], str | None] | None + path: list[str], + logfmt: Callable[[Any, str], str | None] | None, + final_color: str = _PATH_FINAL, ) -> str: - """Format a path as dot notation with prefix in dark grey, final in default.""" + """Format a path as dot notation with prefix in dark grey, final colored.""" components = _format_path_components(path, logfmt) if not components: return "" if len(components) == 1: - return f"{_PATH_FINAL}{components[0]}{_RESET}" + return f"{final_color}{components[0]}{_RESET}" prefix = ".".join(components[:-1]) final = components[-1] - return f"{_PATH_PREFIX}{prefix}.{_RESET}{_PATH_FINAL}{final}{_RESET}" + return f"{_PATH_PREFIX}{prefix}.{_RESET}{final_color}{final}{_RESET}" def _get_nested(data: dict | None, path: list[str]) -> Any: @@ -202,8 +207,6 @@ def _format_change_lines( logfmt: Callable[[Any, str], str | None] | None = None, ) -> list[str]: """Format a single change as one or more lines.""" - path_str = _format_path(path, logfmt=logfmt) - if change_type == "delete": components = _format_path_components(path, logfmt) if len(components) == 1: @@ -213,6 +216,7 @@ def _format_change_lines( return [f" {_PATH_PREFIX}{prefix}.{_RESET}{_DELETE}{final} āœ—{_RESET}"] if change_type == "add": + path_str = _format_path(path, logfmt, final_color=_ADD) if isinstance(value, dict) and value: lines = [f" {path_str} {_SEP}={_RESET}"] formatted_items = [] @@ -232,6 +236,7 @@ def _format_change_lines( return [f" {path_str} {_SEP}={_RESET} {value_str}"] value_str = _format_value(value, ".".join(path), logfmt=logfmt) + path_str = _format_path(path, logfmt=logfmt) return [f" {path_str} {_SEP}={_RESET} {value_str}"] @@ -262,9 +267,20 @@ def format_diff( return lines -def format_action_header(action: str, user: str | None = None) -> str: - """Format the action header line.""" +def format_action_header( + action: str, + user: str | None = None, + extra: str | dict[str, Any] | None = None, +) -> str: + """Format the action header line. + + A string *extra* is appended literally after the action; a dict *extra* + is ignored by the default header (it is meant for ``headerfmt`` + callbacks). + """ action_str = f"{_ACTION}{action}{_RESET}" + if isinstance(extra, str) and extra: + action_str = f"{action_str} {extra}" if user: user_str = f"{_USER}{user}{_RESET}" return f"{action_str} by {user_str}" @@ -276,10 +292,14 @@ def log_change( diff: dict, user: str | None = None, previous: dict | None = None, + extra: str | dict[str, Any] | None = None, logfmt: Callable[[Any, str], str | None] | None = None, + headerfmt: Callable[[str, str | None, Any], str | None] | None = None, *, logger: logging.Logger = transaction_logger, level: int = logging.INFO, + log_header: bool = True, + log_diff: bool = True, ) -> None: """Log a database change with pretty-printed diff. @@ -288,12 +308,31 @@ def log_change( diff: The JSON diff dict. user: Optional already-formatted user name to show in the header. previous: The previous state dict (for determining add vs update). + extra: Optional display-only metadata. A string is appended after + the action in the default header; a dict is passed to + ``headerfmt``. logfmt: Optional formatter callable ``(value, path) -> str | None``. + headerfmt: Optional header formatter callable + ``(action, user, extra) -> str | None`` replacing the default + header. Returning ``None`` falls back to the default header. logger: Logger to write to. Defaults to the ``kanta.transaction`` logger. level: Log level to use. Defaults to ``logging.INFO``. + log_header: Whether to emit the header line. + log_diff: Whether to emit the diff lines. """ - header = format_action_header(action, user) - diff_lines = format_diff(diff, previous, logfmt) + header: str | None = None + if log_header: + if headerfmt is not None: + header = headerfmt(action, user, extra) + if header is None: + header = format_action_header(action, user, extra) + + diff_lines = format_diff(diff, previous, logfmt) if log_diff else [] + + if header is None: + for line in diff_lines: + logger.log(level, line) + return if not diff_lines: logger.log(level, header) diff --git a/kanta/transaction.py b/kanta/transaction.py index 80b4803..0457ec6 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -5,6 +5,7 @@ from __future__ import annotations import logging from contextlib import contextmanager from datetime import datetime +from typing import Any from kanta.diff import compute_diff from kanta.exceptions import DataIntegrityError @@ -21,8 +22,9 @@ def transaction( action: str, *, user: str | None = None, + extra: str | dict[str, Any] | None = None, mtime: bool | datetime = True, - log: bool | logging.Logger = True, + log: bool | logging.Logger | dict[str, bool] = True, ): """Wrap writes in a transaction and yield the live db object.""" if impl.readonly: @@ -82,14 +84,29 @@ def transaction( if resolved is not None: formatted_user = resolved if log is not False: - logger = log if isinstance(log, logging.Logger) else transaction_logger + if isinstance(log, dict): + log_header = bool(log.get("header", True)) + log_diff = bool(log.get("diff", True)) + logger = transaction_logger + else: + log_header = log_diff = True + logger = ( + log if isinstance(log, logging.Logger) else transaction_logger + ) + headerfmt, extra = impl.build_headerfmt( + action, formatted_user, extra, previous, new_dict + ) log_change( action, record.diff, formatted_user, previous, - logfmt, + extra=extra, + logfmt=logfmt, + headerfmt=headerfmt, logger=logger, + log_header=log_header, + log_diff=log_diff, ) except Exception: _logger.warning("Transaction '%s' failed, rolling back changes", action) -- 2.55.0 From f4e0c66907675f86606b0469a0bbe251d1a2096a Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:06:24 +0000 Subject: [PATCH 02/24] Tests for rich logging, apply ruff formatting --- kanta/callbacks.py | 8 +- kanta/kantaimpl.py | 4 +- kanta/transaction.py | 4 +- tests/test_format_diff.py | 24 +++- tests/test_logging.py | 65 +++++++++- tests/test_logheader.py | 251 ++++++++++++++++++++++++++++++++++++++ 6 files changed, 351 insertions(+), 5 deletions(-) create mode 100644 tests/test_logheader.py diff --git a/kanta/callbacks.py b/kanta/callbacks.py index 0d83362..bde0870 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -496,7 +496,13 @@ class CallbackRegistry: if self._data_type is not None and bare is self._data_type: return kind == "bootstrap" if self._kanta_class is not None and bare is self._kanta_class: - return kind in {"bootstrap", "fatal_error", "logfmt", "logmigr", "logheader"} + return kind in { + "bootstrap", + "fatal_error", + "logfmt", + "logmigr", + "logheader", + } return False def _allowed_message(self, kind: str) -> str: diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index f2dfeda..86b70bd 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -330,7 +330,9 @@ class KantaImpl(PersistenceMixin, Generic[T]): ) if record is not None and log is not False: - logger = log if isinstance(log, logging.Logger) else bootstrap_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( diff --git a/kanta/transaction.py b/kanta/transaction.py index 0457ec6..79b416f 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -91,7 +91,9 @@ def transaction( else: log_header = log_diff = True logger = ( - log if isinstance(log, logging.Logger) else transaction_logger + log + if isinstance(log, logging.Logger) + else transaction_logger ) headerfmt, extra = impl.build_headerfmt( action, formatted_user, extra, previous, new_dict diff --git a/tests/test_format_diff.py b/tests/test_format_diff.py index 9bd9e05..ddb8fe4 100644 --- a/tests/test_format_diff.py +++ b/tests/test_format_diff.py @@ -1,4 +1,4 @@ -from kanta.logging import format_diff +from kanta.logging import _ADD, _DELETE, format_diff def test_add(): @@ -6,6 +6,28 @@ def test_add(): assert any("name" in line for line in lines) +def test_add_path_is_green(): + lines = format_diff({"name": "Alice"}, previous={}) + assert any(_ADD in line for line in lines) + + +def test_nested_add_path_final_element_is_green(): + lines = format_diff({"users": {"alice": 1}}, previous={"users": {}}) + assert any(_ADD in line and "alice" in line for line in lines) + + +def test_update_path_not_colored_as_add(): + lines = format_diff({"name": "Bob"}, previous={"name": "Alice"}) + assert lines + assert all(_ADD not in line for line in lines) + + +def test_delete_path_not_colored_as_add(): + lines = format_diff({"$delete": ["old_key"]}, previous={"old_key": 1}) + assert any(_DELETE in line for line in lines) + assert all(_ADD not in line for line in lines) + + def test_update(): lines = format_diff({"name": "Bob"}, previous={"name": "Alice"}) assert any("Bob" in line for line in lines) diff --git a/tests/test_logging.py b/tests/test_logging.py index 739c3d5..a019579 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -2,7 +2,7 @@ import logging import pytest -from kanta.logging import configure_logging, log_change, transaction_logger +from kanta.logging import configure_logging, log_change @pytest.fixture(autouse=True) @@ -46,3 +46,66 @@ def test_log_change_no_diff(capsys): log_change("test", {}) captured = capsys.readouterr() assert "test" in captured.err + + +def test_log_change_appends_extra_string(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging() + log_change("export", {}, extra="mydb.db") + captured = capsys.readouterr() + assert "export" in captured.err + assert "mydb.db" in captured.err + + +def test_log_change_headerfmt_replaces_header(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging() + log_change( + "update", + {}, + headerfmt=lambda action, user, extra: f"CUSTOM {action} {extra['id']}", + extra={"id": 7}, + ) + captured = capsys.readouterr() + assert "CUSTOM update 7" in captured.err + + +def test_log_change_headerfmt_none_falls_back(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging() + log_change("update", {}, user="alice", headerfmt=lambda *args: None) + captured = capsys.readouterr() + assert "update" in captured.err + assert "alice" in captured.err + + +def test_log_change_log_diff_false(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging() + log_change("update", {"counter": 5}, previous={}, log_diff=False) + captured = capsys.readouterr() + assert "update" in captured.err + assert "counter" not in captured.err + + +def test_log_change_log_header_false(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging() + log_change("update", {"counter": 5}, previous={}, log_header=False) + captured = capsys.readouterr() + assert "update" not in captured.err + assert "counter" in captured.err + + +def test_log_change_both_disabled_logs_nothing(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging() + log_change("update", {"counter": 5}, previous={}, log_header=False, log_diff=False) + captured = capsys.readouterr() + assert captured.err == "" diff --git a/tests/test_logheader.py b/tests/test_logheader.py new file mode 100644 index 0000000..1186593 --- /dev/null +++ b/tests/test_logheader.py @@ -0,0 +1,251 @@ +import logging + +import pytest + +from kanta import Kanta +from kanta.callbacks import DictPost, DictPre + +from .support import Data, make_kanta, read_changes + + +def test_logheader_rejects_async(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + with pytest.raises(TypeError, match="must not be async"): + + @kanta.logheader + async def header(action: str) -> str: + return action + + +def test_logheader_rejects_bad_return_annotation(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + with pytest.raises(TypeError, match="must return"): + + @kanta.logheader + def header(action: str) -> int: + return 1 + + +def test_logheader_rejects_unknown_annotation(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + with pytest.raises(TypeError, match="unsupported annotation"): + + @kanta.logheader + def header(action: str, bogus: int) -> str: + return action + + +@pytest.mark.asyncio +async def test_logheader_replaces_default_header(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logheader + def header(action: str, user: str | None, extra: dict | None) -> str: + return f"HDR {action} user={user} session={extra['session']}" + + await kanta.open(log=False) + with kanta.transaction(action="update", user="alice", extra={"session": 3}) as data: + data.counter = 1 + await kanta.close() + + assert "HDR update user=alice session=3" in caplog.text + # The diff body is still logged after the custom header. + assert "counter" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_default_target_is_filename(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "mydb.db", Data, format_config) + + @kanta.logheader + def header(action: str, extra: dict | None) -> str: + return f"target={extra['target']}" + + await kanta.open(log=False) + with kanta.transaction(action="update") as data: + data.counter = 1 + await kanta.close() + + assert "target=mydb.db" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_explicit_target_kept(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "mydb.db", Data, format_config) + + @kanta.logheader + def header(action: str, extra: dict | None) -> str: + return f"target={extra['target']}" + + await kanta.open(log=False) + with kanta.transaction( + action="update", extra={"target": "Project X (abcd1234)"} + ) as data: + data.counter = 1 + await kanta.close() + + assert "target=Project X (abcd1234)" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_injects_states_and_kanta(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logheader + def header( + action: str, + previous: DictPre, + current: DictPost, + kanta: Kanta, + ) -> str: + return ( + f"{action} counter {previous.get('counter')}" + f" -> {current.get('counter')} db={kanta.filename.name}" + ) + + await kanta.open(log=False) + with kanta.transaction(action="increment") as data: + data.counter = 5 + await kanta.close() + + assert "increment counter 0 -> 5 db=test.db" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_chain_first_non_none_wins(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logheader + def first(action: str) -> str | None: + return None + + @kanta.logheader + def second(action: str) -> str: + return f"SECOND {action}" + + await kanta.open(log=False) + with kanta.transaction(action="update") as data: + data.counter = 1 + await kanta.close() + + assert "SECOND update" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_all_none_falls_back_to_default( + tmp_path, format_config, caplog +): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logheader + def header(action: str) -> str | None: + return None + + await kanta.open(log=False) + with kanta.transaction(action="update", user="alice") as data: + data.counter = 1 + await kanta.close() + + assert "update" in caplog.text + assert "alice" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_receives_formatted_user(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logfmt(path="$user") + def resolve_user(value: str) -> str | None: + return "Alice" + + @kanta.logheader + def header(action: str, user: str | None) -> str: + return f"actor={user}" + + await kanta.open(log=False) + with kanta.transaction(action="update", user="uuid-1") as data: + data.counter = 1 + await kanta.close() + + assert "actor=Alice" in caplog.text + + +@pytest.mark.asyncio +async def test_logheader_applies_to_bootstrap(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.bootstrap") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logheader + def header(action: str, extra: dict | None) -> str: + return f"BOOT {action} target={extra['target']}" + + await kanta.open() + await kanta.close() + + assert "BOOT bootstrap target=test.db" in caplog.text + + +@pytest.mark.asyncio +async def test_transaction_extra_string_in_default_header( + tmp_path, format_config, caplog +): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + await kanta.open(log=False) + with kanta.transaction(action="export", extra="mydb.db") as data: + data.counter = 1 + await kanta.close() + + assert "export" in caplog.text + assert "mydb.db" in caplog.text + + +@pytest.mark.asyncio +async def test_extra_is_not_persisted(tmp_path, format_config): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + + await kanta.open(log=False) + with kanta.transaction( + action="update", user="alice", extra={"session": 3, "target": "X"} + ) as data: + data.counter = 1 + await kanta.close() + + record = read_changes(path, format_config)[-1] + assert record.a == "update" + assert record.u == "alice" + + +@pytest.mark.asyncio +async def test_transaction_log_dict_toggles(tmp_path, format_config, caplog): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + await kanta.open(log=False) + with kanta.transaction( + action="myaction", log={"header": True, "diff": False} + ) as data: + data.counter = 1 + with kanta.transaction( + action="otheraction", log={"header": False, "diff": True} + ) as data: + data.counter = 2 + await kanta.close() + + # First transaction: header only. + assert "myaction" in caplog.text + # Second transaction: diff only, no header. + assert "otheraction" not in caplog.text + assert "counter" in caplog.text -- 2.55.0 From 450952cd6480c774034ca99178b9bd968227cecd Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:07:05 +0000 Subject: [PATCH 03/24] Document transaction log headers: extra, logheader, toggles --- docs/database.md | 34 ++++++++++++++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/docs/database.md b/docs/database.md index 6c5765b..f7f09eb 100644 --- a/docs/database.md +++ b/docs/database.md @@ -197,6 +197,40 @@ def resolve_user_key(value: str) -> str | None: return names_by_id.get(value) ``` +#### Transaction Log Headers + +- 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. +- `kanta.transaction(..., extra=...)` accepts display-only metadata that is + used for logging and is never persisted in the `ChangeRecord`: + - a string is appended literally after the action in the default header, + - a dict is passed to a registered `@kanta.logheader` callback; if it has + no `"target"` key, the database filename is inserted as the target. +- Register a `@kanta.logheader` callback to replace the entire header line. + It may declare `action: str`, `user: str | None` and `extra: dict | None` + parameters, and can also have `DictPre`/`DictPost` state dicts and the + `Kanta` instance injected. It must be synchronous and return `str | None`. +- Multiple logheader callbacks are stacked in registration order; the first + callback to return a non-`None` result wins. If all return `None`, Kanta + falls back to the default header. The `user` value passed to the callback + has already been through the `logfmt` formatters. +- The header and diff parts can be toggled independently per transaction: + `kanta.transaction(..., log={"header": True, "diff": False})`. + +```python +@kanta.logheader +def format_header(action: str, user: str | None, extra: dict | None) -> str: + session = extra.get("session_id", "-") + return f"{user:<20} {session:>2} {action} {extra['target']}" + +with kanta.transaction( + action="update", + user="alice", + extra={"session_id": 3, "target": "Project Name (abcd1234)"}, +) as data: + ... +``` + ## Migrations - Migration source is configured on `Kanta(...)` via `migrations=`. -- 2.55.0 From 5b0d676175c081a2b0bd4df9a0eeeb1f1315057d Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:28:58 +0000 Subject: [PATCH 04/24] Add feature demo app under demo/ --- demo/.gitignore | 1 + demo/main.py | 152 ++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 153 insertions(+) create mode 100644 demo/.gitignore create mode 100644 demo/main.py diff --git a/demo/.gitignore b/demo/.gitignore new file mode 100644 index 0000000..3f68360 --- /dev/null +++ b/demo/.gitignore @@ -0,0 +1 @@ +demo.db diff --git a/demo/main.py b/demo/main.py new file mode 100644 index 0000000..05b0491 --- /dev/null +++ b/demo/main.py @@ -0,0 +1,152 @@ +"""Kanta feature demo. + +Run from the project root: python demo/main.py + +Demonstrates bootstrap, colored transaction diffs, logfmt value formatting, +custom log headers, logging toggles, rollback, and migrations. The database +is recreated on every run; everything else lives in this file. +""" + +import asyncio +import logging +from pathlib import Path +from types import ModuleType + +import msgspec + +from kanta import Kanta +from kanta.logging import _ACTION, _ACTOR, _RESET, _SESSION, _TARGET +from kanta.logging import configure_logging + +DB = Path(__file__).with_name("demo.db") + +# Fake directory: user id -> display name, resolved by the logfmt callbacks. +USERS = {"u1": "Alice", "u2": "Bob", "u3": "Carol"} + + +class DataV1(msgspec.Struct): + """Original schema (version 0).""" + + users: dict[str, dict] = {} + counter: int = 0 + + +class Data(msgspec.Struct): + """Current schema: migration v1 adds the settings section.""" + + users: dict[str, dict] = {} + counter: int = 0 + settings: dict[str, str] = {} + + +def migrate_v1(d: dict) -> None: + """Add settings section""" + d["settings"] = {"theme": "dark"} + + +migrations = ModuleType("demo_migrations") +migrations.migrate_v1 = migrate_v1 + + +def add_logfmts(kanta: Kanta) -> None: + """Resolve user ids to display names in headers and diff paths.""" + + @kanta.logfmt(path="$user") + def resolve_actor(value: str) -> str | None: + return USERS.get(value) + + @kanta.logfmt + def resolve_user_key(value: str, path: str) -> str | None: + if path.startswith("users."): + return USERS.get(value) + return None + + +def add_header(kanta: Kanta) -> None: + """Aligned rich header: actor, session id, action, target.""" + + @kanta.logheader + def header(action: str, user: str | None, extra: dict | None) -> str: + actor = f"{_ACTOR}{user or '-':<8}{_RESET}" + session = f"{_SESSION}{extra.get('session_id', '-'):>2}{_RESET}" + target = f"{_TARGET}{extra['target']}{_RESET}" + return f"{actor} {session} {_ACTION}{action}{_RESET} {target}" + + +async def main() -> None: + DB.unlink(missing_ok=True) + + print("=== Standard logging: bootstrap, diffs, toggles, rollback ===", flush=True) + + kanta = Kanta(DB, DataV1()) + add_logfmts(kanta) + + @kanta.bootstrap + def seed(data: DataV1) -> None: + data.users["u1"] = {"name": "Alice", "role": "admin"} + + await kanta.open() + + with kanta.transaction(action="create", user="u2") as data: + data.users["u2"] = {"name": "Bob", "role": "user"} + + with kanta.transaction(action="update", user="u1") as data: + data.users["u2"]["role"] = "editor" + data.counter = 1 + + with kanta.transaction(action="delete", user="u1") as data: + del data.users["u2"] + + # Display-only extra string, appended after the action. + with kanta.transaction(action="export", user="u1", extra=DB.name) as data: + data.counter = 2 + + # Compact logging: diff only (no header) ... + with kanta.transaction( + action="repair", log={"header": False, "diff": True} + ) as data: + data.users["u3"] = {"name": "Carol", "role": "user"} + + # A failing transaction rolls back and logs a warning. + try: + with kanta.transaction(action="reset", user="u1") as data: + data.counter = 99 + raise ValueError("simulated failure") + except ValueError: + pass + + # ... and header only (no diff). + with kanta.transaction( + action="import", user="u1", log={"header": True, "diff": False} + ) as data: + data.counter = 3 + + await kanta.close() + + print("=== Reopen with migrations and a custom log header ===", flush=True) + + kanta = Kanta(DB, Data(), migrations=migrations) + add_logfmts(kanta) + add_header(kanta) + await kanta.open() + + # No target given: defaults to the database filename. + with kanta.transaction(action="update", user="u1", extra={"session_id": 3}) as data: + data.settings["theme"] = "light" + + with kanta.transaction( + action="update", + user="u2", + extra={"session_id": 7, "target": "settings (demo)"}, + ) as data: + data.settings["lang"] = "en" + + await kanta.close() + + print(f"=== Database written to {DB} ===", flush=True) + + +if __name__ == "__main__": + configure_logging() + logging.getLogger("kanta").setLevel(logging.DEBUG) # show migration diffs + asyncio.run(main()) -- 2.55.0 From 123e910873fa20efa37158c530ec6e317b614366 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:55:09 +0000 Subject: [PATCH 05/24] Add @kanta.clock hook replacing the UTC clock for all record and snapshot timestamps --- kanta/kanta.py | 19 ++++++++ kanta/kantaimpl.py | 6 ++- kanta/persistence.py | 34 ++++++++++++- kanta/snapshot.py | 9 +++- tests/test_clock.py | 114 +++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 177 insertions(+), 5 deletions(-) create mode 100644 tests/test_clock.py diff --git a/kanta/kanta.py b/kanta/kanta.py index 93eb19b..ea76bdf 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -253,6 +253,25 @@ class Kanta(Generic[T]): return _register return _register(fn) + def clock(self, fn=None): + """Register a clock callback replacing the default UTC clock. + + Can be used as ``@kanta.clock``. The callback takes no arguments and + must return a :class:`~datetime.datetime`; its value is used for all + record timestamps (``ts``, and ``m`` when ``mtime`` is ``True``) and + snapshot timestamps. Register before :meth:`open` so that bootstrap + and migration records use the custom clock as well. This is mainly + useful for tests and reproducible demos. + """ + + def _register(callback): + self._impl.add_clock(callback) + return callback + + if fn is None: + return _register + return _register(fn) + def logmigr(self, fn=None): """Register a migration logging callback. diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index 86b70bd..aedc4bb 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -296,7 +296,11 @@ class KantaImpl(PersistenceMixin, Generic[T]): self.snapshot.request_force() await self.flush() self.snapshot.maybe_write( - self.file, self.version, self.statedict, m=self.mtime + self.file, + self.version, + self.statedict, + m=self.mtime, + now=self.now(), ) if migrations_ran and migration_result is not None: diff --git a/kanta/persistence.py b/kanta/persistence.py index 5113256..76a5fe8 100644 --- a/kanta/persistence.py +++ b/kanta/persistence.py @@ -4,8 +4,10 @@ from __future__ import annotations import asyncio import copy +import inspect import logging from collections import deque +from collections.abc import Callable from datetime import UTC, datetime from pathlib import Path from typing import Any @@ -41,6 +43,7 @@ class PersistenceMixin: opened: bool readonly: bool mtime: datetime | None + clock: Callable[[], datetime] | None def __init__(self, **kwargs: Any) -> None: """Initialize persistence-owned state used by mixin methods.""" @@ -62,6 +65,31 @@ class PersistenceMixin: self.flush_interval = flush_interval self.version = 0 self.mtime: datetime | None = None + self.clock: Callable[[], datetime] | None = None + + def add_clock(self, callback) -> None: + """Register a clock callback ``() -> datetime`` replacing the UTC clock.""" + if not callable(callback): + raise TypeError("clock callback must be callable") + for param in inspect.signature(callback).parameters.values(): + if param.default is inspect.Parameter.empty and param.kind in ( + param.POSITIONAL_ONLY, + param.POSITIONAL_OR_KEYWORD, + param.KEYWORD_ONLY, + ): + raise TypeError("clock callback must not require arguments") + self.clock = callback + + def now(self) -> datetime: + """Current time from the registered clock (default: UTC now).""" + if self.clock is None: + return datetime.now(UTC) + ts = self.clock() + if not isinstance(ts, datetime): + raise TypeError( + f"clock callback must return a datetime, got {type(ts).__name__}" + ) + return ts def add_fatal_error(self, callback) -> None: """Register one fatal error callback in call order.""" @@ -100,7 +128,9 @@ class PersistenceMixin: def maybe_snapshot(self) -> None: """Evaluate and possibly write a snapshot from current state.""" - self.snapshot.maybe_write(self.file, self.version, self.statedict, m=self.mtime) + self.snapshot.maybe_write( + self.file, self.version, self.statedict, m=self.mtime, now=self.now() + ) def queue_change( self, @@ -128,7 +158,7 @@ class PersistenceMixin: The queued :class:`ChangeRecord`, or ``None`` if the diff was empty and *force* is ``False``. """ - now = datetime.now(UTC) + now = self.now() if mtime is True: m = now diff --git a/kanta/snapshot.py b/kanta/snapshot.py index 8896f50..c6389fe 100644 --- a/kanta/snapshot.py +++ b/kanta/snapshot.py @@ -38,11 +38,16 @@ class SnapshotState: self.changes += count def maybe_write( - self, file, version: int, state: dict, m: datetime | None = None + self, + file, + version: int, + state: dict, + m: datetime | None = None, + now: datetime | None = None, ) -> None: """Write snapshot when thresholds/time policy allows it.""" force = self._force_pending - now = datetime.now(UTC) + now = now if now is not None else datetime.now(UTC) if not force: if self.changes < self._min_diffs: return diff --git a/tests/test_clock.py b/tests/test_clock.py new file mode 100644 index 0000000..10cb4dc --- /dev/null +++ b/tests/test_clock.py @@ -0,0 +1,114 @@ +from datetime import UTC, datetime, timedelta + +import pytest + +from .support import ( + Data, + make_kanta, + make_migrations_module, + read_changes, + read_last_snapshot, +) + +T0 = datetime(2026, 1, 1, 12, 0, tzinfo=UTC) + + +def test_clock_rejects_non_callable(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + with pytest.raises(TypeError, match="must be callable"): + kanta.clock(42) + + +def test_clock_rejects_required_argument(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + with pytest.raises(TypeError, match="must not require arguments"): + + @kanta.clock + def fake_now(tz) -> datetime: + return T0 + + +@pytest.mark.asyncio +async def test_clock_rejects_non_datetime_result(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.clock + def fake_now() -> datetime: + return "noon" + + with pytest.raises(TypeError, match="must return a datetime"): + await kanta.open(log=False) + + +@pytest.mark.asyncio +async def test_clock_controls_record_timestamps(tmp_path, format_config): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + current = T0 + + @kanta.clock + def fake_now() -> datetime: + return current + + await kanta.open(log=False) + current = T0 + timedelta(hours=1) + with kanta.transaction(action="update") as data: + data.counter = 1 + current = T0 + timedelta(hours=2) + with kanta.transaction(action="repair", mtime=False) as data: + data.counter = 2 + await kanta.close() + + bootstrap, update, repair = read_changes(path, format_config) + assert bootstrap.ts == T0 + assert bootstrap.m == T0 + assert update.ts == T0 + timedelta(hours=1) + assert update.m == T0 + timedelta(hours=1) + # System operation: stamped by the clock, but m is not updated. + assert repair.ts == T0 + timedelta(hours=2) + assert repair.m is None + assert kanta.mtime == T0 + timedelta(hours=1) + + +@pytest.mark.asyncio +async def test_clock_controls_migration_and_snapshot_timestamps( + tmp_path, format_config +): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + + @kanta.clock + def fake_now() -> datetime: + return T0 + + await kanta.open(log=False) + await kanta.close() + + def migrate_v1(d): + """Bump counter""" + d["counter"] = 1 + + migrations = make_migrations_module("clock_migrations", "migrate_v1", migrate_v1) + t1 = T0 + timedelta(days=1) + kanta2 = make_kanta(path, Data, format_config, migrations=migrations) + + @kanta2.clock + def fake_now2() -> datetime: + return t1 + + await kanta2.open(log=False) + await kanta2.close() + + migrate_records = [ + r for r in read_changes(path, format_config) if r.a.startswith("migrate:") + ] + assert migrate_records + assert all(r.ts == t1 for r in migrate_records) + + snapshot = read_last_snapshot(path, format_config) + assert snapshot is not None + assert snapshot.ts == t1 + # mtime is carried forward from the last real modification. + assert snapshot.m == T0 -- 2.55.0 From 8d9e948d27224ea81702551f19719b70954a0af4 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:57:00 +0000 Subject: [PATCH 06/24] Demo: deterministic clock, # section banners, .kantadb extension, raw record dump --- demo/.gitignore | 2 +- demo/main.py | 59 ++++++++++++++++++++++++++++++++++++++++-------- docs/database.md | 9 ++++++++ 3 files changed, 60 insertions(+), 10 deletions(-) diff --git a/demo/.gitignore b/demo/.gitignore index 3f68360..74df5b7 100644 --- a/demo/.gitignore +++ b/demo/.gitignore @@ -1 +1 @@ -demo.db +demo.kantadb diff --git a/demo/main.py b/demo/main.py index 05b0491..ba3efe6 100644 --- a/demo/main.py +++ b/demo/main.py @@ -3,12 +3,14 @@ Run from the project root: python demo/main.py Demonstrates bootstrap, colored transaction diffs, logfmt value formatting, -custom log headers, logging toggles, rollback, and migrations. The database -is recreated on every run; everything else lives in this file. +custom log headers, logging toggles, rollback, migrations, and a custom clock. +The database is recreated with fixed timestamps on every run; everything else +lives in this file. """ import asyncio import logging +from datetime import UTC, datetime, timedelta from pathlib import Path from types import ModuleType @@ -18,12 +20,25 @@ from kanta import Kanta from kanta.logging import _ACTION, _ACTOR, _RESET, _SESSION, _TARGET from kanta.logging import configure_logging -DB = Path(__file__).with_name("demo.db") +DB = Path(__file__).with_name("demo.kantadb") # Fake directory: user id -> display name, resolved by the logfmt callbacks. USERS = {"u1": "Alice", "u2": "Bob", "u3": "Carol"} +class Clock: + """Deterministic clock: manually advanced, so every run is identical.""" + + def __init__(self) -> None: + self.current = datetime(2026, 8, 6, 12, 0, tzinfo=UTC) + + def advance(self, **kwargs) -> None: + self.current += timedelta(**kwargs) + + +clock = Clock() + + class DataV1(msgspec.Struct): """Original schema (version 0).""" @@ -48,6 +63,14 @@ migrations = ModuleType("demo_migrations") migrations.migrate_v1 = migrate_v1 +def add_clock(kanta: Kanta) -> None: + """Use the shared deterministic clock for all record timestamps.""" + + @kanta.clock + def fake_now() -> datetime: + return clock.current + + def add_logfmts(kanta: Kanta) -> None: """Resolve user ids to display names in headers and diff paths.""" @@ -73,12 +96,17 @@ def add_header(kanta: Kanta) -> None: return f"{actor} {session} {_ACTION}{action}{_RESET} {target}" +def section(title: str) -> None: + print(f"\n# {title}", flush=True) + + async def main() -> None: DB.unlink(missing_ok=True) - print("=== Standard logging: bootstrap, diffs, toggles, rollback ===", flush=True) + section("Standard logging: bootstrap, diffs, toggles, rollback") kanta = Kanta(DB, DataV1()) + add_clock(kanta) add_logfmts(kanta) @kanta.bootstrap @@ -87,23 +115,29 @@ async def main() -> None: await kanta.open() + clock.advance(minutes=2) with kanta.transaction(action="create", user="u2") as data: data.users["u2"] = {"name": "Bob", "role": "user"} + clock.advance(minutes=5) with kanta.transaction(action="update", user="u1") as data: data.users["u2"]["role"] = "editor" data.counter = 1 + clock.advance(seconds=30) with kanta.transaction(action="delete", user="u1") as data: del data.users["u2"] # Display-only extra string, appended after the action. + clock.advance(hours=1) with kanta.transaction(action="export", user="u1", extra=DB.name) as data: data.counter = 2 - # Compact logging: diff only (no header) ... + # Compact logging, diff only: a system fix stamped by the clock, but the + # modification time (m) is not updated. + clock.advance(minutes=10) with kanta.transaction( - action="repair", log={"header": False, "diff": True} + action="repair", mtime=False, log={"header": False, "diff": True} ) as data: data.users["u3"] = {"name": "Carol", "role": "user"} @@ -115,7 +149,8 @@ async def main() -> None: except ValueError: pass - # ... and header only (no diff). + # Compact logging, header only. + clock.advance(minutes=5) with kanta.transaction( action="import", user="u1", log={"header": True, "diff": False} ) as data: @@ -123,17 +158,21 @@ async def main() -> None: await kanta.close() - print("=== Reopen with migrations and a custom log header ===", flush=True) + section("Reopen with migrations and a custom log header") + clock.advance(days=1) kanta = Kanta(DB, Data(), migrations=migrations) + add_clock(kanta) add_logfmts(kanta) add_header(kanta) await kanta.open() # No target given: defaults to the database filename. + clock.advance(minutes=3) with kanta.transaction(action="update", user="u1", extra={"session_id": 3}) as data: data.settings["theme"] = "light" + clock.advance(minutes=1) with kanta.transaction( action="update", user="u2", @@ -143,7 +182,9 @@ async def main() -> None: await kanta.close() - print(f"=== Database written to {DB} ===", flush=True) + # The pretty names only exist in the logs; the database stores raw ids. + section("Raw database records (user ids and timestamps, not pretty names)") + print(DB.read_text(), end="", flush=True) if __name__ == "__main__": diff --git a/docs/database.md b/docs/database.md index f7f09eb..475650e 100644 --- a/docs/database.md +++ b/docs/database.md @@ -163,6 +163,15 @@ when they have a default value. - Multiple handlers are supported and invoked in registration order. A failing handler is logged and does not prevent subsequent handlers from running. +#### Clock + +- `@kanta.clock` registers a callback `() -> datetime` that replaces the + default UTC clock. Its value is used for all record timestamps (`ts`, and + `m` when `mtime` is `True`) and for snapshot timestamps. +- Register before `open()` so that bootstrap and migration records use the + custom clock as well. This is mainly useful for tests and reproducible + demos. + #### Transaction Log Formatting - Logfmt callbacks prettify identifiers in the change log and are registered with -- 2.55.0 From 5d66d423dadee80ae6cf195de3b85057eb99dc00 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 00:01:16 +0000 Subject: [PATCH 07/24] Lazy clock reads; demo: auto-advancing +1h clock, module-level setup --- demo/main.py | 122 ++++++++++++++++++------------------------- docs/database.md | 2 + kanta/kanta.py | 8 +-- kanta/kantaimpl.py | 2 +- kanta/persistence.py | 15 +++--- kanta/snapshot.py | 16 +++--- tests/test_clock.py | 21 ++++++++ 7 files changed, 98 insertions(+), 88 deletions(-) diff --git a/demo/main.py b/demo/main.py index ba3efe6..e826eba 100644 --- a/demo/main.py +++ b/demo/main.py @@ -25,18 +25,15 @@ DB = Path(__file__).with_name("demo.kantadb") # Fake directory: user id -> display name, resolved by the logfmt callbacks. USERS = {"u1": "Alice", "u2": "Bob", "u3": "Carol"} - -class Clock: - """Deterministic clock: manually advanced, so every run is identical.""" - - def __init__(self) -> None: - self.current = datetime(2026, 8, 6, 12, 0, tzinfo=UTC) - - def advance(self, **kwargs) -> None: - self.current += timedelta(**kwargs) +_now = datetime(2026, 8, 6, tzinfo=UTC) -clock = Clock() +def fake_now() -> datetime: + """Deterministic clock: starts at midnight, +1h on every read.""" + global _now + ts = _now + _now += timedelta(hours=1) + return ts class DataV1(msgspec.Struct): @@ -63,37 +60,43 @@ migrations = ModuleType("demo_migrations") migrations.migrate_v1 = migrate_v1 -def add_clock(kanta: Kanta) -> None: - """Use the shared deterministic clock for all record timestamps.""" - - @kanta.clock - def fake_now() -> datetime: - return clock.current +def resolve_actor(value: str) -> str | None: + """Resolve the transaction user id to a display name.""" + return USERS.get(value) -def add_logfmts(kanta: Kanta) -> None: - """Resolve user ids to display names in headers and diff paths.""" - - @kanta.logfmt(path="$user") - def resolve_actor(value: str) -> str | None: +def resolve_user_key(value: str, path: str) -> str | None: + """Resolve user ids in diff paths to display names.""" + if path.startswith("users."): return USERS.get(value) - - @kanta.logfmt - def resolve_user_key(value: str, path: str) -> str | None: - if path.startswith("users."): - return USERS.get(value) - return None + return None -def add_header(kanta: Kanta) -> None: +def header(action: str, user: str | None, extra: dict | None) -> str: """Aligned rich header: actor, session id, action, target.""" + actor = f"{_ACTOR}{user or '-':<8}{_RESET}" + session = f"{_SESSION}{extra.get('session_id', '-'):>2}{_RESET}" + target = f"{_TARGET}{extra['target']}{_RESET}" + return f"{actor} {session} {_ACTION}{action}{_RESET} {target}" - @kanta.logheader - def header(action: str, user: str | None, extra: dict | None) -> str: - actor = f"{_ACTOR}{user or '-':<8}{_RESET}" - session = f"{_SESSION}{extra.get('session_id', '-'):>2}{_RESET}" - target = f"{_TARGET}{extra['target']}{_RESET}" - return f"{actor} {session} {_ACTION}{action}{_RESET} {target}" + +def seed(data: DataV1) -> None: + """Bootstrap: create the initial admin user.""" + data.users["u1"] = {"name": "Alice", "role": "admin"} + + +# Phase 1 instance: default logging, original schema. +kanta_v0 = Kanta(DB, DataV1()) +# Phase 2 instance: migrations and a custom log header. +kanta_v1 = Kanta(DB, Data(), migrations=migrations) + +for k in (kanta_v0, kanta_v1): + k.clock(fake_now) + k.logfmt(resolve_user_key) + k.logfmt(resolve_actor, path="$user") + +kanta_v0.bootstrap(seed) +kanta_v1.logheader(header) def section(title: str) -> None: @@ -104,83 +107,62 @@ async def main() -> None: DB.unlink(missing_ok=True) section("Standard logging: bootstrap, diffs, toggles, rollback") + await kanta_v0.open() - kanta = Kanta(DB, DataV1()) - add_clock(kanta) - add_logfmts(kanta) - - @kanta.bootstrap - def seed(data: DataV1) -> None: - data.users["u1"] = {"name": "Alice", "role": "admin"} - - await kanta.open() - - clock.advance(minutes=2) - with kanta.transaction(action="create", user="u2") as data: + with kanta_v0.transaction(action="create", user="u2") as data: data.users["u2"] = {"name": "Bob", "role": "user"} - clock.advance(minutes=5) - with kanta.transaction(action="update", user="u1") as data: + with kanta_v0.transaction(action="update", user="u1") as data: data.users["u2"]["role"] = "editor" data.counter = 1 - clock.advance(seconds=30) - with kanta.transaction(action="delete", user="u1") as data: + with kanta_v0.transaction(action="delete", user="u1") as data: del data.users["u2"] # Display-only extra string, appended after the action. - clock.advance(hours=1) - with kanta.transaction(action="export", user="u1", extra=DB.name) as data: + with kanta_v0.transaction(action="export", user="u1", extra=DB.name) as data: data.counter = 2 # Compact logging, diff only: a system fix stamped by the clock, but the # modification time (m) is not updated. - clock.advance(minutes=10) - with kanta.transaction( + with kanta_v0.transaction( action="repair", mtime=False, log={"header": False, "diff": True} ) as data: data.users["u3"] = {"name": "Carol", "role": "user"} # A failing transaction rolls back and logs a warning. try: - with kanta.transaction(action="reset", user="u1") as data: + with kanta_v0.transaction(action="reset", user="u1") as data: data.counter = 99 raise ValueError("simulated failure") except ValueError: pass # Compact logging, header only. - clock.advance(minutes=5) - with kanta.transaction( + with kanta_v0.transaction( action="import", user="u1", log={"header": True, "diff": False} ) as data: data.counter = 3 - await kanta.close() + await kanta_v0.close() section("Reopen with migrations and a custom log header") - - clock.advance(days=1) - kanta = Kanta(DB, Data(), migrations=migrations) - add_clock(kanta) - add_logfmts(kanta) - add_header(kanta) - await kanta.open() + await kanta_v1.open() # No target given: defaults to the database filename. - clock.advance(minutes=3) - with kanta.transaction(action="update", user="u1", extra={"session_id": 3}) as data: + with kanta_v1.transaction( + action="update", user="u1", extra={"session_id": 3} + ) as data: data.settings["theme"] = "light" - clock.advance(minutes=1) - with kanta.transaction( + with kanta_v1.transaction( action="update", user="u2", extra={"session_id": 7, "target": "settings (demo)"}, ) as data: data.settings["lang"] = "en" - await kanta.close() + await kanta_v1.close() # The pretty names only exist in the logs; the database stores raw ids. section("Raw database records (user ids and timestamps, not pretty names)") diff --git a/docs/database.md b/docs/database.md index 475650e..e4d2aaa 100644 --- a/docs/database.md +++ b/docs/database.md @@ -168,6 +168,8 @@ when they have a default value. - `@kanta.clock` registers a callback `() -> datetime` that replaces the default UTC clock. Its value is used for all record timestamps (`ts`, and `m` when `mtime` is `True`) and for snapshot timestamps. +- The clock is only read when a timestamp is actually produced; no-op + transactions and skipped snapshot checks do not read it. - Register before `open()` so that bootstrap and migration records use the custom clock as well. This is mainly useful for tests and reproducible demos. diff --git a/kanta/kanta.py b/kanta/kanta.py index ea76bdf..73d152e 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -259,9 +259,11 @@ class Kanta(Generic[T]): Can be used as ``@kanta.clock``. The callback takes no arguments and must return a :class:`~datetime.datetime`; its value is used for all record timestamps (``ts``, and ``m`` when ``mtime`` is ``True``) and - snapshot timestamps. Register before :meth:`open` so that bootstrap - and migration records use the custom clock as well. This is mainly - useful for tests and reproducible demos. + snapshot timestamps. The clock is only read when a timestamp is + actually produced, so read-count-dependent clocks (e.g. advancing on + every read) stay deterministic. Register before :meth:`open` so that + bootstrap and migration records use the custom clock as well. This is + mainly useful for tests and reproducible demos. """ def _register(callback): diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index aedc4bb..93e5b75 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -300,7 +300,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): self.version, self.statedict, m=self.mtime, - now=self.now(), + now=self.now, ) if migrations_ran and migration_result is not None: diff --git a/kanta/persistence.py b/kanta/persistence.py index 76a5fe8..81b0436 100644 --- a/kanta/persistence.py +++ b/kanta/persistence.py @@ -129,7 +129,7 @@ class PersistenceMixin: def maybe_snapshot(self) -> None: """Evaluate and possibly write a snapshot from current state.""" self.snapshot.maybe_write( - self.file, self.version, self.statedict, m=self.mtime, now=self.now() + self.file, self.version, self.statedict, m=self.mtime, now=self.now ) def queue_change( @@ -158,6 +158,13 @@ class PersistenceMixin: The queued :class:`ChangeRecord`, or ``None`` if the diff was empty and *force* is ``False``. """ + diff = compute_diff(self.statedict, current) + if not diff: + if not force: + return None + diff = {} + + # The clock is only read when a record is actually queued. now = self.now() if mtime is True: @@ -169,12 +176,6 @@ class PersistenceMixin: else: raise TypeError("mtime must be True, False, or a datetime") - diff = compute_diff(self.statedict, current) - if not diff: - if not force: - return None - diff = {} - record = ChangeRecord( ts=now, a=action, diff --git a/kanta/snapshot.py b/kanta/snapshot.py index c6389fe..e97357b 100644 --- a/kanta/snapshot.py +++ b/kanta/snapshot.py @@ -3,6 +3,7 @@ from __future__ import annotations import logging +from collections.abc import Callable from datetime import UTC, datetime from kanta.structs import Snapshot @@ -43,23 +44,24 @@ class SnapshotState: version: int, state: dict, m: datetime | None = None, - now: datetime | None = None, + now: Callable[[], datetime] | None = None, ) -> None: """Write snapshot when thresholds/time policy allows it.""" force = self._force_pending - now = now if now is not None else datetime.now(UTC) + if not force and self.changes < self._min_diffs: + return + # The clock is only read when a snapshot may actually be written. + ts = now() if now is not None else datetime.now(UTC) if not force: - if self.changes < self._min_diffs: + if ts.weekday() != 6: # 6 = Sunday return - if now.weekday() != 6: # 6 = Sunday - return - sunday_midnight = now.replace(hour=0, minute=0, second=0, microsecond=0) + sunday_midnight = ts.replace(hour=0, minute=0, second=0, microsecond=0) if self.ts is not None and self.ts >= sunday_midnight: return if not file.is_open: return try: - self._write(file, version, state, now, m=m) + self._write(file, version, state, ts, m=m) self._force_pending = False except Exception as exc: _logger.error("snapshot: failed to write snapshot: %r", exc) diff --git a/tests/test_clock.py b/tests/test_clock.py index 10cb4dc..4845996 100644 --- a/tests/test_clock.py +++ b/tests/test_clock.py @@ -72,6 +72,27 @@ async def test_clock_controls_record_timestamps(tmp_path, format_config): assert kanta.mtime == T0 + timedelta(hours=1) +@pytest.mark.asyncio +async def test_clock_not_read_without_changes(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + reads = 0 + + @kanta.clock + def fake_now() -> datetime: + nonlocal reads + reads += 1 + return T0 + + await kanta.open(log=False) # bootstrap record: one read + reads = 0 + + with kanta.transaction(action="noop"): + pass # no changes, no record, no clock read + await kanta.close() # no snapshot written, no clock read + + assert reads == 0 + + @pytest.mark.asyncio async def test_clock_controls_migration_and_snapshot_timestamps( tmp_path, format_config -- 2.55.0 From 72944c9410a07b625b24f7885cab891b6a9837cd Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 00:06:54 +0000 Subject: [PATCH 08/24] Demo: resolve user names from database state, kanta instances at top with stacked decorators --- demo/main.py | 69 +++++++++++++++++++++++++--------------------------- 1 file changed, 33 insertions(+), 36 deletions(-) diff --git a/demo/main.py b/demo/main.py index e826eba..cab1588 100644 --- a/demo/main.py +++ b/demo/main.py @@ -17,24 +17,12 @@ from types import ModuleType import msgspec from kanta import Kanta +from kanta.callbacks import DictPost, DictPre from kanta.logging import _ACTION, _ACTOR, _RESET, _SESSION, _TARGET from kanta.logging import configure_logging DB = Path(__file__).with_name("demo.kantadb") -# Fake directory: user id -> display name, resolved by the logfmt callbacks. -USERS = {"u1": "Alice", "u2": "Bob", "u3": "Carol"} - -_now = datetime(2026, 8, 6, tzinfo=UTC) - - -def fake_now() -> datetime: - """Deterministic clock: starts at midnight, +1h on every read.""" - global _now - ts = _now - _now += timedelta(hours=1) - return ts - class DataV1(msgspec.Struct): """Original schema (version 0).""" @@ -59,19 +47,41 @@ def migrate_v1(d: dict) -> None: migrations = ModuleType("demo_migrations") migrations.migrate_v1 = migrate_v1 +# Phase 1 instance: default logging, original schema. +kanta_v0 = Kanta(DB, DataV1()) +# Phase 2 instance: migrations and a custom log header. +kanta_v1 = Kanta(DB, Data(), migrations=migrations) -def resolve_actor(value: str) -> str | None: - """Resolve the transaction user id to a display name.""" - return USERS.get(value) +_now = datetime(2026, 8, 6, tzinfo=UTC) -def resolve_user_key(value: str, path: str) -> str | None: - """Resolve user ids in diff paths to display names.""" - if path.startswith("users."): - return USERS.get(value) +@kanta_v0.clock +@kanta_v1.clock +def fake_now() -> datetime: + """Deterministic clock: starts at midnight, +1h on every read.""" + global _now + ts = _now + _now += timedelta(hours=1) + return ts + + +@kanta_v0.logfmt +@kanta_v1.logfmt +def resolve_user( + value: str, path: str, previous: DictPre, current: DictPost +) -> str | None: + """Resolve user ids to names from the database state itself.""" + if path != "$user" and not path.startswith("users."): + return None + # Post-change state first, then pre-change (deleted users are only there). + for state in (current, previous): + name = state.get("users", {}).get(value, {}).get("name") + if name: + return name return None +@kanta_v1.logheader def header(action: str, user: str | None, extra: dict | None) -> str: """Aligned rich header: actor, session id, action, target.""" actor = f"{_ACTOR}{user or '-':<8}{_RESET}" @@ -80,25 +90,12 @@ def header(action: str, user: str | None, extra: dict | None) -> str: return f"{actor} {session} {_ACTION}{action}{_RESET} {target}" +@kanta_v0.bootstrap def seed(data: DataV1) -> None: - """Bootstrap: create the initial admin user.""" + """Create the initial admin user.""" data.users["u1"] = {"name": "Alice", "role": "admin"} -# Phase 1 instance: default logging, original schema. -kanta_v0 = Kanta(DB, DataV1()) -# Phase 2 instance: migrations and a custom log header. -kanta_v1 = Kanta(DB, Data(), migrations=migrations) - -for k in (kanta_v0, kanta_v1): - k.clock(fake_now) - k.logfmt(resolve_user_key) - k.logfmt(resolve_actor, path="$user") - -kanta_v0.bootstrap(seed) -kanta_v1.logheader(header) - - def section(title: str) -> None: print(f"\n# {title}", flush=True) @@ -157,7 +154,7 @@ async def main() -> None: with kanta_v1.transaction( action="update", - user="u2", + user="u3", extra={"session_id": 7, "target": "settings (demo)"}, ) as data: data.settings["lang"] = "en" -- 2.55.0 From ec08c185aa3d921876269cb6f374f83366f8305d Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 00:08:50 +0000 Subject: [PATCH 09/24] Demo: use the script itself as the migrations module --- demo/main.py | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/demo/main.py b/demo/main.py index cab1588..a0b2135 100644 --- a/demo/main.py +++ b/demo/main.py @@ -10,9 +10,9 @@ lives in this file. import asyncio import logging +import sys from datetime import UTC, datetime, timedelta from pathlib import Path -from types import ModuleType import msgspec @@ -44,13 +44,10 @@ def migrate_v1(d: dict) -> None: d["settings"] = {"theme": "dark"} -migrations = ModuleType("demo_migrations") -migrations.migrate_v1 = migrate_v1 - # Phase 1 instance: default logging, original schema. kanta_v0 = Kanta(DB, DataV1()) -# Phase 2 instance: migrations and a custom log header. -kanta_v1 = Kanta(DB, Data(), migrations=migrations) +# Phase 2 instance: migrations (scanned from this script) and a custom header. +kanta_v1 = Kanta(DB, Data(), migrations=sys.modules[__name__]) _now = datetime(2026, 8, 6, tzinfo=UTC) -- 2.55.0 From e0725c57385b46a74b91004aed047d02712f40a2 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 00:31:04 +0000 Subject: [PATCH 10/24] Kanta colors log header parts: extra is a plain string, logheader callbacks receive pre-colored parts --- kanta/callbacks.py | 19 ++++--- kanta/kanta.py | 32 ++++++------ kanta/kantaimpl.py | 41 +++++++-------- kanta/logging.py | 58 +++++++++++---------- kanta/transaction.py | 5 +- tests/test_logging.py | 30 +++++++++-- tests/test_logheader.py | 108 ++++++++++++++++++++++++---------------- 7 files changed, 173 insertions(+), 120 deletions(-) diff --git a/kanta/callbacks.py b/kanta/callbacks.py index bde0870..0770536 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -63,7 +63,7 @@ class InjectionContext: migration_result: MigrationResult | None = None action: str | None = None user: str | None = None - extra: Any = None + extra: str | None = None @dataclass @@ -245,14 +245,13 @@ class CallbackRegistry: @staticmethod def _logheader_param_annotation(name: str, ann: Any) -> Any: """Map logheader parameter names to their injection sentinels.""" - bare = CallbackRegistry._unwrap_optional(ann) - if name == "action" and bare is str: - return _HeaderAction - if name == "user" and bare is str: - return _HeaderUser - if name == "extra" and (bare is dict or get_origin(bare) is dict): - return _HeaderExtra - return None + if CallbackRegistry._unwrap_optional(ann) is not str: + return None + return { + "action": _HeaderAction, + "user": _HeaderUser, + "extra": _HeaderExtra, + }.get(name) def _validate_function( self, @@ -520,7 +519,7 @@ class CallbackRegistry: if kind == "logheader": parts.append("action: str") parts.append("user: str | None") - parts.append("extra: dict | None") + parts.append("extra: str | None") if kind in {"logfmt", "logheader"}: parts.append("Annotated[dict, 'pre']") parts.append("Annotated[dict, 'post']") diff --git a/kanta/kanta.py b/kanta/kanta.py index 73d152e..a7d9485 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -5,7 +5,7 @@ import logging from datetime import datetime from pathlib import Path from types import ModuleType, SimpleNamespace -from typing import Any, Generic, TypeVar +from typing import Generic, TypeVar from kanta.kantaimpl import KantaImpl from kanta.serialization import JsonSerializer, Serializer @@ -316,17 +316,18 @@ class Kanta(Generic[T]): def logheader(self, fn=None): """Register a transaction log header callback. - Can be used as ``@kanta.logheader``. The callback formats the entire - header line printed before a transaction diff. It may declare - ``action: str``, ``user: str | None`` and ``extra: dict | None`` - parameters, and can also have ``DictPre``/``DictPost`` state dicts and - the ``Kanta`` instance injected. It must return ``str`` (or ``None`` - to fall through to the next callback, then to the default header). + Can be used as ``@kanta.logheader``. The callback composes the header + line printed before a transaction diff from the parts it declares: + ``action: str``, ``user: str`` and ``extra: str``. Kanta applies its + header colors to the parts before calling the callback, and a missing + ``user``/``extra`` is passed as an empty string, so callbacks only + arrange text ā€” no color codes, fallbacks, or padding. ``DictPre``/ + ``DictPost`` state dicts and the ``Kanta`` instance can also be + injected. The callback must be synchronous and return ``str`` (or + ``None`` to fall through to the next callback, then to the default + header). If registered, this replaces the default ``action by user`` header. - The ``extra`` metadata passed to :meth:`transaction` is display-only - and is never persisted; when no ``target`` key is supplied it defaults - to the database filename. """ def _register(callback): @@ -342,7 +343,7 @@ class Kanta(Generic[T]): action: str, *, user: str | None = None, - extra: str | dict[str, Any] | None = None, + extra: str | None = None, mtime: bool | datetime = True, log: bool | logging.Logger | dict[str, bool] = True, ): @@ -353,11 +354,10 @@ class Kanta(Generic[T]): user: Optional user identifier stored in metadata and rendered in the log header. Register a ``@kanta.logfmt`` callback to format the user value; the path ``"$user"`` is passed for this case. - extra: Optional display-only metadata used for logging; it is not - persisted in the change record. A string is appended after - the action in the default header. A dict is passed to a - registered ``@kanta.logheader`` callback; if it has no - ``"target"`` key, the database filename is used. + extra: Optional display-only string appended after the action in + the log header (colored by Kanta), or passed to a registered + ``@kanta.logheader`` callback. It is never persisted in the + change record. mtime: Controls the modification time ``m``. ``True`` (default) sets ``m`` to the current UTC time. ``False`` omits ``m`` so the previous modification time remains in effect; this is used for diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index 93e5b75..a2f2682 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -13,7 +13,13 @@ 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, bootstrap_logger, log_change, migration_logger +from kanta.logging import ( + _USER_PATH, + bootstrap_logger, + colorize_header_parts, + 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 @@ -89,37 +95,33 @@ class KantaImpl(PersistenceMixin, Generic[T]): self, action: str, user: str | None, - extra: str | dict[str, Any] | None, + extra: str | None, previous: dict | None, current: dict | None, - ) -> tuple[Callable[..., str | None] | None, str | dict[str, Any] | None]: - """Build a headerfmt callable and normalized extra for ``log_change``. + ) -> Callable[..., str | None] | None: + """Build a headerfmt callable for ``log_change``. - Returns ``(None, extra)`` unchanged when no logheader callback is - registered. Otherwise the extra dict gets a default ``target`` (the - database filename) when not supplied, so single-database apps get a - useful header with no extra code. + The logheader callbacks receive the header parts with Kanta's colors + already applied (missing user/extra as empty strings). Returns + ``None`` when no logheader callback is registered. """ if not self.callback_registry.has("logheader"): - return None, extra - if extra is None: - extra = {} - if isinstance(extra, dict) and "target" not in extra: - extra = {**extra, "target": self.filename.name} + return None + action_str, user_str, extra_str = colorize_header_parts(action, user, extra) ctx = InjectionContext( - action=action, - user=user, - extra=extra, + action=action_str, + user=user_str, + extra=extra_str, previous_state=previous, current_state=current, kanta=self._kanta, ) registry = self.callback_registry - def headerfmt(action: str, user: str | None, extra: Any) -> str | None: + def headerfmt(action: str, user: str, extra: str) -> str | None: return registry.resolve_logheader(ctx) - return headerfmt, extra + return headerfmt async def _handle_migration_log( self, @@ -350,7 +352,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): resolved = logfmt(formatted_user, _USER_PATH) if resolved is not None: formatted_user = resolved - headerfmt, extra = self.build_headerfmt( + headerfmt = self.build_headerfmt( self.bootstrap_action, formatted_user, None, {}, current ) log_change( @@ -358,7 +360,6 @@ class KantaImpl(PersistenceMixin, Generic[T]): record.diff, formatted_user, previous={}, - extra=extra, logfmt=logfmt, headerfmt=headerfmt, logger=logger, diff --git a/kanta/logging.py b/kanta/logging.py index 38d9b59..10f4cc3 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -33,9 +33,7 @@ _DELETE = "\033[1;31m" # Red for deletions _ADD = "\033[0;32m" # Green for additions _ACTION = "\033[1;34m" # Bold blue for action name _USER = "\033[0;34m" # Blue for user display -_ACTOR = "\033[0;36m" # Cyan for actor/label header fields -_SESSION = "\033[38;5;226m" # Bright yellow for session/request ids -_TARGET = "\033[38;5;250m" # White for target object names/ids +_TARGET = "\033[38;5;250m" # White for the extra/target display # Metadata path used when formatting the transaction actor. _USER_PATH = "$user" @@ -267,24 +265,35 @@ def format_diff( return lines +def colorize_header_parts( + action: str, + user: str | None = None, + extra: str | None = None, +) -> tuple[str, str, str]: + """Apply Kanta's header colors to the action, user, and extra parts. + + ``None`` user/extra become empty strings so custom header callbacks can + interpolate the parts directly without fallbacks. + """ + action_str = f"{_ACTION}{action}{_RESET}" + user_str = f"{_USER}{user}{_RESET}" if user else "" + extra_str = f"{_TARGET}{extra}{_RESET}" if extra else "" + return action_str, user_str, extra_str + + def format_action_header( action: str, user: str | None = None, - extra: str | dict[str, Any] | None = None, + extra: str | None = None, ) -> str: - """Format the action header line. - - A string *extra* is appended literally after the action; a dict *extra* - is ignored by the default header (it is meant for ``headerfmt`` - callbacks). - """ - action_str = f"{_ACTION}{action}{_RESET}" - if isinstance(extra, str) and extra: - action_str = f"{action_str} {extra}" - if user: - user_str = f"{_USER}{user}{_RESET}" - return f"{action_str} by {user_str}" - return action_str + """Format the default action header line.""" + action_str, user_str, extra_str = colorize_header_parts(action, user, extra) + header = action_str + if extra_str: + header = f"{header} {extra_str}" + if user_str: + header = f"{header} by {user_str}" + return header def log_change( @@ -292,9 +301,9 @@ def log_change( diff: dict, user: str | None = None, previous: dict | None = None, - extra: str | dict[str, Any] | None = None, + extra: str | None = None, logfmt: Callable[[Any, str], str | None] | None = None, - headerfmt: Callable[[str, str | None, Any], str | None] | None = None, + headerfmt: Callable[[str, str, str], str | None] | None = None, *, logger: logging.Logger = transaction_logger, level: int = logging.INFO, @@ -308,13 +317,12 @@ def log_change( diff: The JSON diff dict. user: Optional already-formatted user name to show in the header. previous: The previous state dict (for determining add vs update). - extra: Optional display-only metadata. A string is appended after - the action in the default header; a dict is passed to - ``headerfmt``. + extra: Optional display-only string appended after the action in the + default header (colored by Kanta), or passed to ``headerfmt``. logfmt: Optional formatter callable ``(value, path) -> str | None``. - headerfmt: Optional header formatter callable - ``(action, user, extra) -> str | None`` replacing the default - header. Returning ``None`` falls back to the default header. + headerfmt: Optional header formatter callable receiving the + pre-colored ``(action, user, extra)`` parts and returning the + header line. Returning ``None`` falls back to the default header. logger: Logger to write to. Defaults to the ``kanta.transaction`` logger. level: Log level to use. Defaults to ``logging.INFO``. log_header: Whether to emit the header line. diff --git a/kanta/transaction.py b/kanta/transaction.py index 79b416f..f0de37e 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -5,7 +5,6 @@ from __future__ import annotations import logging from contextlib import contextmanager from datetime import datetime -from typing import Any from kanta.diff import compute_diff from kanta.exceptions import DataIntegrityError @@ -22,7 +21,7 @@ def transaction( action: str, *, user: str | None = None, - extra: str | dict[str, Any] | None = None, + extra: str | None = None, mtime: bool | datetime = True, log: bool | logging.Logger | dict[str, bool] = True, ): @@ -95,7 +94,7 @@ def transaction( if isinstance(log, logging.Logger) else transaction_logger ) - headerfmt, extra = impl.build_headerfmt( + headerfmt = impl.build_headerfmt( action, formatted_user, extra, previous, new_dict ) log_change( diff --git a/tests/test_logging.py b/tests/test_logging.py index a019579..ad9e8d8 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -2,7 +2,29 @@ import logging import pytest -from kanta.logging import configure_logging, log_change +from kanta.logging import ( + _ACTION, + _RESET, + _TARGET, + _USER, + colorize_header_parts, + configure_logging, + log_change, +) + + +def test_colorize_header_parts(): + action, user, extra = colorize_header_parts("update", "alice", "tgt") + assert action == f"{_ACTION}update{_RESET}" + assert user == f"{_USER}alice{_RESET}" + assert extra == f"{_TARGET}tgt{_RESET}" + + +def test_colorize_header_parts_missing_user_and_extra(): + action, user, extra = colorize_header_parts("update") + assert action == f"{_ACTION}update{_RESET}" + assert user == "" + assert extra == "" @pytest.fixture(autouse=True) @@ -55,7 +77,7 @@ def test_log_change_appends_extra_string(capsys): log_change("export", {}, extra="mydb.db") captured = capsys.readouterr() assert "export" in captured.err - assert "mydb.db" in captured.err + assert f"{_TARGET}mydb.db{_RESET}" in captured.err def test_log_change_headerfmt_replaces_header(capsys): @@ -65,8 +87,8 @@ def test_log_change_headerfmt_replaces_header(capsys): log_change( "update", {}, - headerfmt=lambda action, user, extra: f"CUSTOM {action} {extra['id']}", - extra={"id": 7}, + headerfmt=lambda action, user, extra: f"CUSTOM {action} {extra}", + extra="7", ) captured = capsys.readouterr() assert "CUSTOM update 7" in captured.err diff --git a/tests/test_logheader.py b/tests/test_logheader.py index 1186593..bdbb6ca 100644 --- a/tests/test_logheader.py +++ b/tests/test_logheader.py @@ -4,10 +4,21 @@ import pytest from kanta import Kanta from kanta.callbacks import DictPost, DictPre +from kanta.logging import _ACTION, _RESET, _TARGET, _USER, configure_logging from .support import Data, make_kanta, read_changes +@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_logheader_rejects_async(tmp_path, format_config): kanta = make_kanta(tmp_path / "test.db", Data, format_config) @@ -38,59 +49,74 @@ def test_logheader_rejects_unknown_annotation(tmp_path, format_config): return action +def test_logheader_rejects_dict_extra(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + with pytest.raises(TypeError, match="unsupported annotation"): + + @kanta.logheader + def header(action: str, extra: dict) -> str: + return action + + @pytest.mark.asyncio async def test_logheader_replaces_default_header(tmp_path, format_config, caplog): caplog.set_level(logging.INFO, logger="kanta.transaction") kanta = make_kanta(tmp_path / "test.db", Data, format_config) @kanta.logheader - def header(action: str, user: str | None, extra: dict | None) -> str: - return f"HDR {action} user={user} session={extra['session']}" + def header(action: str, user: str, extra: str) -> str: + return f"{user} {action} {extra}" await kanta.open(log=False) - with kanta.transaction(action="update", user="alice", extra={"session": 3}) as data: + with kanta.transaction(action="update", user="alice", extra="tgt") as data: data.counter = 1 await kanta.close() - assert "HDR update user=alice session=3" in caplog.text + # caplog strips ANSI codes; the colors are verified via capsys below. + assert "alice update tgt" in caplog.text # The diff body is still logged after the custom header. assert "counter" in caplog.text @pytest.mark.asyncio -async def test_logheader_default_target_is_filename(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "mydb.db", Data, format_config) +async def test_logheader_parts_are_colored_by_kanta(tmp_path, format_config, capsys): + logging.getLogger("kanta").handlers.clear() + configure_logging() + kanta = make_kanta(tmp_path / "test.db", Data, format_config) @kanta.logheader - def header(action: str, extra: dict | None) -> str: - return f"target={extra['target']}" + def header(action: str, user: str, extra: str) -> str: + return f"{user} {action} {extra}" + + await kanta.open(log=False) + with kanta.transaction(action="update", user="alice", extra="tgt") as data: + data.counter = 1 + await kanta.close() + + err = capsys.readouterr().err + assert f"{_USER}alice{_RESET}" in err + assert f"{_ACTION}update{_RESET}" in err + assert f"{_TARGET}tgt{_RESET}" in err + + +@pytest.mark.asyncio +async def test_logheader_missing_user_and_extra_are_empty( + tmp_path, format_config, caplog +): + caplog.set_level(logging.INFO, logger="kanta.transaction") + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + @kanta.logheader + def header(action: str, user: str, extra: str) -> str: + return f"<{user}><{extra}>" await kanta.open(log=False) with kanta.transaction(action="update") as data: data.counter = 1 await kanta.close() - assert "target=mydb.db" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_explicit_target_kept(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "mydb.db", Data, format_config) - - @kanta.logheader - def header(action: str, extra: dict | None) -> str: - return f"target={extra['target']}" - - await kanta.open(log=False) - with kanta.transaction( - action="update", extra={"target": "Project X (abcd1234)"} - ) as data: - data.counter = 1 - await kanta.close() - - assert "target=Project X (abcd1234)" in caplog.text + assert "<><>" in caplog.text @pytest.mark.asyncio @@ -106,7 +132,7 @@ async def test_logheader_injects_states_and_kanta(tmp_path, format_config, caplo kanta: Kanta, ) -> str: return ( - f"{action} counter {previous.get('counter')}" + f"counter {previous.get('counter')}" f" -> {current.get('counter')} db={kanta.filename.name}" ) @@ -115,7 +141,7 @@ async def test_logheader_injects_states_and_kanta(tmp_path, format_config, caplo data.counter = 5 await kanta.close() - assert "increment counter 0 -> 5 db=test.db" in caplog.text + assert "counter 0 -> 5 db=test.db" in caplog.text @pytest.mark.asyncio @@ -128,15 +154,15 @@ async def test_logheader_chain_first_non_none_wins(tmp_path, format_config, capl return None @kanta.logheader - def second(action: str) -> str: - return f"SECOND {action}" + def second(action: str, extra: str) -> str: + return f"SECOND {extra}" await kanta.open(log=False) - with kanta.transaction(action="update") as data: + with kanta.transaction(action="update", extra="marked") as data: data.counter = 1 await kanta.close() - assert "SECOND update" in caplog.text + assert "SECOND marked" in caplog.text @pytest.mark.asyncio @@ -169,7 +195,7 @@ async def test_logheader_receives_formatted_user(tmp_path, format_config, caplog return "Alice" @kanta.logheader - def header(action: str, user: str | None) -> str: + def header(action: str, user: str) -> str: return f"actor={user}" await kanta.open(log=False) @@ -186,13 +212,13 @@ async def test_logheader_applies_to_bootstrap(tmp_path, format_config, caplog): kanta = make_kanta(tmp_path / "test.db", Data, format_config) @kanta.logheader - def header(action: str, extra: dict | None) -> str: - return f"BOOT {action} target={extra['target']}" + def header(action: str) -> str: + return f"BOOT {action}" await kanta.open() await kanta.close() - assert "BOOT bootstrap target=test.db" in caplog.text + assert "BOOT bootstrap" in caplog.text @pytest.mark.asyncio @@ -217,9 +243,7 @@ async def test_extra_is_not_persisted(tmp_path, format_config): kanta = make_kanta(path, Data, format_config) await kanta.open(log=False) - with kanta.transaction( - action="update", user="alice", extra={"session": 3, "target": "X"} - ) as data: + with kanta.transaction(action="update", user="alice", extra="session-3") as data: data.counter = 1 await kanta.close() -- 2.55.0 From 1cd99aef01b344d69be1ca5fd41ac157a023bd11 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 00:33:56 +0000 Subject: [PATCH 11/24] Demo: plain-text custom header colored by Kanta, rename migration, str extras --- demo/main.py | 129 +++++++++++++++++++---------------------------- docs/database.md | 33 +++++------- 2 files changed, 66 insertions(+), 96 deletions(-) diff --git a/demo/main.py b/demo/main.py index a0b2135..5609918 100644 --- a/demo/main.py +++ b/demo/main.py @@ -18,11 +18,8 @@ import msgspec from kanta import Kanta from kanta.callbacks import DictPost, DictPre -from kanta.logging import _ACTION, _ACTOR, _RESET, _SESSION, _TARGET from kanta.logging import configure_logging -DB = Path(__file__).with_name("demo.kantadb") - class DataV1(msgspec.Struct): """Original schema (version 0).""" @@ -32,34 +29,31 @@ class DataV1(msgspec.Struct): class Data(msgspec.Struct): - """Current schema: migration v1 adds the settings section.""" + """Current schema: migration v1 renames counter to total.""" users: dict[str, dict] = {} - counter: int = 0 - settings: dict[str, str] = {} + total: int = 0 def migrate_v1(d: dict) -> None: - """Add settings section""" - d["settings"] = {"theme": "dark"} + """Rename counter to total""" + d["total"] = d.pop("counter") -# Phase 1 instance: default logging, original schema. -kanta_v0 = Kanta(DB, DataV1()) -# Phase 2 instance: migrations (scanned from this script) and a custom header. -kanta_v1 = Kanta(DB, Data(), migrations=sys.modules[__name__]) +filename = Path(__file__).with_name("demo.kantadb") +# For demonstration purposes, we use "original v0" and "modified v1" in this same script +kanta_v0 = Kanta(filename, DataV1()) +kanta_v1 = Kanta(filename, Data(), migrations=sys.modules[__name__]) -_now = datetime(2026, 8, 6, tzinfo=UTC) +_now = datetime(2027, 1, 1, tzinfo=UTC) @kanta_v0.clock @kanta_v1.clock -def fake_now() -> datetime: - """Deterministic clock: starts at midnight, +1h on every read.""" +def fake_clock() -> datetime: global _now - ts = _now _now += timedelta(hours=1) - return ts + return _now @kanta_v0.logfmt @@ -79,12 +73,9 @@ def resolve_user( @kanta_v1.logheader -def header(action: str, user: str | None, extra: dict | None) -> str: - """Aligned rich header: actor, session id, action, target.""" - actor = f"{_ACTOR}{user or '-':<8}{_RESET}" - session = f"{_SESSION}{extra.get('session_id', '-'):>2}{_RESET}" - target = f"{_TARGET}{extra['target']}{_RESET}" - return f"{actor} {session} {_ACTION}{action}{_RESET} {target}" +def header(action: str, user: str, extra: str) -> str: + """Custom header: Kanta colors the parts, we just arrange them.""" + return f"{user} {action} {extra}" @kanta_v0.bootstrap @@ -98,69 +89,53 @@ def section(title: str) -> None: async def main() -> None: - DB.unlink(missing_ok=True) + filename.unlink(missing_ok=True) - section("Standard logging: bootstrap, diffs, toggles, rollback") - await kanta_v0.open() + section("Database creation with v0 schema and basic access") + # Open and close automatically; you can also `await kanta.open()` instead + async with kanta_v0 as kanta: + with kanta.transaction(action="create", user="u2") as data: + data.users["u2"] = {"name": "Bob", "role": "user"} - with kanta_v0.transaction(action="create", user="u2") as data: - data.users["u2"] = {"name": "Bob", "role": "user"} + with kanta.transaction(action="update", user="u1") as data: + data.users["u2"]["role"] = "editor" + data.counter = 1 - with kanta_v0.transaction(action="update", user="u1") as data: - data.users["u2"]["role"] = "editor" - data.counter = 1 + with kanta.transaction(action="delete", user="u1") as data: + del data.users["u2"] - with kanta_v0.transaction(action="delete", user="u1") as data: - del data.users["u2"] + # Display-only extra string, appended after the action. + with kanta.transaction(action="export", user="u1", extra=filename.name) as data: + data.counter = 2 - # Display-only extra string, appended after the action. - with kanta_v0.transaction(action="export", user="u1", extra=DB.name) as data: - data.counter = 2 + # Compact logging, diff only: a system fix stamped by the clock, but the + # modification time (m) is not updated. + with kanta.transaction( + action="repair", mtime=False, log={"header": False, "diff": True} + ) as data: + data.users["u3"] = {"name": "Carol", "role": "user"} - # Compact logging, diff only: a system fix stamped by the clock, but the - # modification time (m) is not updated. - with kanta_v0.transaction( - action="repair", mtime=False, log={"header": False, "diff": True} - ) as data: - data.users["u3"] = {"name": "Carol", "role": "user"} + # A failing transaction rolls back and logs a warning. + try: + with kanta.transaction(action="reset", user="u1") as data: + data.counter = 99 + raise ValueError("simulated failure") + except ValueError: + pass - # A failing transaction rolls back and logs a warning. - try: - with kanta_v0.transaction(action="reset", user="u1") as data: - data.counter = 99 - raise ValueError("simulated failure") - except ValueError: - pass + # Compact logging, header only. + with kanta.transaction( + action="import", user="u1", log={"header": True, "diff": False} + ) as data: + data.counter = 3 - # Compact logging, header only. - with kanta_v0.transaction( - action="import", user="u1", log={"header": True, "diff": False} - ) as data: - data.counter = 3 + section("A later version of our application with new data model and migrations") + async with kanta_v1 as kanta: + with kanta.transaction(action="update", user="u1", extra=filename.name) as data: + data.total = 4 - await kanta_v0.close() - - section("Reopen with migrations and a custom log header") - await kanta_v1.open() - - # No target given: defaults to the database filename. - with kanta_v1.transaction( - action="update", user="u1", extra={"session_id": 3} - ) as data: - data.settings["theme"] = "light" - - with kanta_v1.transaction( - action="update", - user="u3", - extra={"session_id": 7, "target": "settings (demo)"}, - ) as data: - data.settings["lang"] = "en" - - await kanta_v1.close() - - # The pretty names only exist in the logs; the database stores raw ids. - section("Raw database records (user ids and timestamps, not pretty names)") - print(DB.read_text(), end="", flush=True) + with kanta.transaction(action="create", user="u3", extra="Dave (u4)") as data: + data.users["u4"] = {"name": "Dave", "role": "user"} if __name__ == "__main__": diff --git a/docs/database.md b/docs/database.md index e4d2aaa..a69c634 100644 --- a/docs/database.md +++ b/docs/database.md @@ -212,33 +212,28 @@ 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. -- `kanta.transaction(..., extra=...)` accepts display-only metadata that is - used for logging and is never persisted in the `ChangeRecord`: - - a string is appended literally after the action in the default header, - - a dict is passed to a registered `@kanta.logheader` callback; if it has - no `"target"` key, the database filename is inserted as the target. -- Register a `@kanta.logheader` callback to replace the entire header line. - It may declare `action: str`, `user: str | None` and `extra: dict | None` - parameters, and can also have `DictPre`/`DictPost` state dicts and the - `Kanta` instance injected. It must be synchronous and return `str | None`. +- `kanta.transaction(..., extra="...")` accepts a display-only string that is + appended after the action in the default header (colored by Kanta); it is + never persisted in the `ChangeRecord`. +- Register a `@kanta.logheader` callback to compose a custom header. Declare + any of `action: str`, `user: str`, `extra: str`: Kanta passes the parts + with its header colors already applied (missing `user`/`extra` as empty + strings), so callbacks only arrange text ā€” no color codes, fallbacks, or + padding. `DictPre`/`DictPost` state dicts and the `Kanta` instance can + also be injected. The callback must be synchronous and return `str | None`. - Multiple logheader callbacks are stacked in registration order; the first callback to return a non-`None` result wins. If all return `None`, Kanta - falls back to the default header. The `user` value passed to the callback - has already been through the `logfmt` formatters. + falls back to the default header. The `user` part has already been through + the `logfmt` formatters. - The header and diff parts can be toggled independently per transaction: `kanta.transaction(..., log={"header": True, "diff": False})`. ```python @kanta.logheader -def format_header(action: str, user: str | None, extra: dict | None) -> str: - session = extra.get("session_id", "-") - return f"{user:<20} {session:>2} {action} {extra['target']}" +def format_header(action: str, user: str, extra: str) -> str: + return f"{user} {action} {extra}" -with kanta.transaction( - action="update", - user="alice", - extra={"session_id": 3, "target": "Project Name (abcd1234)"}, -) as data: +with kanta.transaction(action="update", user="alice", extra="Project X") as data: ... ``` -- 2.55.0 From 9e19a1bf21085cd679112ed63435d10dd9383b81 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 00:44:06 +0000 Subject: [PATCH 12/24] Remove logheader callback feature; keep Kanta-colored extra string in default header --- demo/main.py | 38 +++--- docs/database.md | 23 +--- kanta/callbacks.py | 72 +---------- kanta/kanta.py | 30 +---- kanta/kantaimpl.py | 49 +------ kanta/logging.py | 11 +- kanta/transaction.py | 4 - tests/test_logging.py | 24 ---- tests/test_logheader.py | 275 ---------------------------------------- 9 files changed, 29 insertions(+), 497 deletions(-) delete mode 100644 tests/test_logheader.py diff --git a/demo/main.py b/demo/main.py index 5609918..6baad27 100644 --- a/demo/main.py +++ b/demo/main.py @@ -3,7 +3,7 @@ Run from the project root: python demo/main.py Demonstrates bootstrap, colored transaction diffs, logfmt value formatting, -custom log headers, logging toggles, rollback, migrations, and a custom clock. +logging toggles, rollback, migrations, and a custom clock. The database is recreated with fixed timestamps on every run; everything else lives in this file. """ @@ -21,16 +21,28 @@ from kanta.callbacks import DictPost, DictPre from kanta.logging import configure_logging -class DataV1(msgspec.Struct): - """Original schema (version 0).""" +filename = Path(__file__).with_name("demo.kantadb") +# For demonstration purposes, we use "original v0" and "modified v1" in this same script +# Normally your app would only have the latest supported data model + + +class Data(msgspec.Struct): # type: ignore - intentionally redefined later users: dict[str, dict] = {} counter: int = 0 -class Data(msgspec.Struct): - """Current schema: migration v1 renames counter to total.""" +kanta_v0 = Kanta(filename, Data()) + +@kanta_v0.bootstrap +def bootstrap(data: Data) -> None: + """Create the initial admin user.""" + data.users["u1"] = {"name": "Alice", "role": "admin"} + + +# Redefinition to simulate new version with counter renamed to total +class Data(msgspec.Struct): users: dict[str, dict] = {} total: int = 0 @@ -40,11 +52,9 @@ def migrate_v1(d: dict) -> None: d["total"] = d.pop("counter") -filename = Path(__file__).with_name("demo.kantadb") -# For demonstration purposes, we use "original v0" and "modified v1" in this same script -kanta_v0 = Kanta(filename, DataV1()) kanta_v1 = Kanta(filename, Data(), migrations=sys.modules[__name__]) + _now = datetime(2027, 1, 1, tzinfo=UTC) @@ -72,18 +82,6 @@ def resolve_user( return None -@kanta_v1.logheader -def header(action: str, user: str, extra: str) -> str: - """Custom header: Kanta colors the parts, we just arrange them.""" - return f"{user} {action} {extra}" - - -@kanta_v0.bootstrap -def seed(data: DataV1) -> None: - """Create the initial admin user.""" - data.users["u1"] = {"name": "Alice", "role": "admin"} - - def section(title: str) -> None: print(f"\n# {title}", flush=True) diff --git a/docs/database.md b/docs/database.md index a69c634..99ec5ca 100644 --- a/docs/database.md +++ b/docs/database.md @@ -213,30 +213,11 @@ 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. - `kanta.transaction(..., extra="...")` accepts a display-only string that is - appended after the action in the default header (colored by Kanta); it is - never persisted in the `ChangeRecord`. -- Register a `@kanta.logheader` callback to compose a custom header. Declare - any of `action: str`, `user: str`, `extra: str`: Kanta passes the parts - with its header colors already applied (missing `user`/`extra` as empty - strings), so callbacks only arrange text ā€” no color codes, fallbacks, or - padding. `DictPre`/`DictPost` state dicts and the `Kanta` instance can - also be injected. The callback must be synchronous and return `str | None`. -- Multiple logheader callbacks are stacked in registration order; the first - callback to return a non-`None` result wins. If all return `None`, Kanta - falls back to the default header. The `user` part has already been through - the `logfmt` formatters. + appended after the action in the header (colored by Kanta); it is never + persisted in the `ChangeRecord`. - The header and diff parts can be toggled independently per transaction: `kanta.transaction(..., log={"header": True, "diff": False})`. -```python -@kanta.logheader -def format_header(action: str, user: str, extra: str) -> str: - return f"{user} {action} {extra}" - -with kanta.transaction(action="update", user="alice", extra="Project X") as data: - ... -``` - ## Migrations - Migration source is configured on `Kanta(...)` via `migrations=`. diff --git a/kanta/callbacks.py b/kanta/callbacks.py index 0770536..0155a1e 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -61,9 +61,6 @@ class InjectionContext: previous_state: dict | None = None current_state: dict | None = None migration_result: MigrationResult | None = None - action: str | None = None - user: str | None = None - extra: str | None = None @dataclass @@ -104,7 +101,6 @@ class CallbackRegistry: "bootstrap": [], "fatal_error": [], "logmigr": [], - "logheader": [], } self._logfmt_callbacks: list[_LogFmtFunctionSpec | _LogFmtClassSpec] = [] @@ -135,18 +131,6 @@ class CallbackRegistry: if not callable(callback): raise TypeError(f"{kind} callback must be callable") - if kind == "logheader": - if inspect.iscoroutinefunction(callback): - raise TypeError("logheader callbacks must not be async") - return_ann = inspect.signature(callback).return_annotation - if return_ann is not inspect.Signature.empty: - resolved = self._resolve_raw_annotation(return_ann, callback) - if not self._is_optional_str(resolved): - raise TypeError( - f"logheader callback {callback.__name__} must return " - f"str | None, got {resolved!r}" - ) - params = self._validate_function(callback, kind) is_async = inspect.iscoroutinefunction(callback) @@ -233,26 +217,6 @@ class CallbackRegistry: return format_value - def resolve_logheader(self, ctx: InjectionContext) -> str | None: - """Invoke logheader callbacks; the first non-None result wins.""" - for reg in self._callbacks["logheader"]: - kwargs = self._build_kwargs(reg.params, ctx) - result = reg.callback(**kwargs) - if result is not None: - return result - return None - - @staticmethod - def _logheader_param_annotation(name: str, ann: Any) -> Any: - """Map logheader parameter names to their injection sentinels.""" - if CallbackRegistry._unwrap_optional(ann) is not str: - return None - return { - "action": _HeaderAction, - "user": _HeaderUser, - "extra": _HeaderExtra, - }.get(name) - def _validate_function( self, callback: Callable[..., Any], @@ -276,11 +240,6 @@ class CallbackRegistry: continue ann = self._resolve_raw_annotation(param.annotation, callback) - if kind == "logheader": - header_ann = self._logheader_param_annotation(name, ann) - if header_ann is not None: - params.append((name, header_ann)) - continue if not self._is_allowed(kind, ann): if param.default is inspect.Parameter.empty: raise TypeError( @@ -485,9 +444,9 @@ class CallbackRegistry: def _is_allowed(self, kind: str, ann: Any) -> bool: bare = self._unwrap_optional(ann) if self._matches_state_annotation(bare, "pre"): - return kind in {"logfmt", "logheader"} + return kind == "logfmt" if self._matches_state_annotation(bare, "post"): - return kind in {"logfmt", "logheader"} + return kind == "logfmt" if bare is DatabaseError: return kind == "fatal_error" if bare is MigrationResult: @@ -500,7 +459,6 @@ class CallbackRegistry: "fatal_error", "logfmt", "logmigr", - "logheader", } return False @@ -509,29 +467,19 @@ class CallbackRegistry: if kind == "bootstrap": if self._data_type is not None: parts.append(self._data_type.__name__) - if kind in {"bootstrap", "fatal_error", "logfmt", "logmigr", "logheader"}: + if kind in {"bootstrap", "fatal_error", "logfmt", "logmigr"}: if self._kanta_class is not None: parts.append(self._kanta_class.__name__) if kind == "fatal_error": parts.append("DatabaseError") if kind == "logmigr": parts.append("MigrationResult") - if kind == "logheader": - parts.append("action: str") - parts.append("user: str | None") - parts.append("extra: str | None") - if kind in {"logfmt", "logheader"}: + if kind == "logfmt": parts.append("Annotated[dict, 'pre']") parts.append("Annotated[dict, 'post']") return ", ".join(parts) if parts else "none" def _resolve_annotation(self, ann: Any, ctx: InjectionContext) -> Any: - if ann is _HeaderAction: - return ctx.action - if ann is _HeaderUser: - return ctx.user - if ann is _HeaderExtra: - return ctx.extra bare = self._unwrap_optional(ann) if self._matches_state_annotation(bare, "pre"): return ctx.previous_state @@ -589,18 +537,6 @@ class CallbackRegistry: return type(None) in args and any(arg is str for arg in args) -class _HeaderAction: - """Sentinel annotation injecting the transaction action.""" - - -class _HeaderUser: - """Sentinel annotation injecting the transaction user.""" - - -class _HeaderExtra: - """Sentinel annotation injecting the display-only extra metadata.""" - - class _Unresolved: pass diff --git a/kanta/kanta.py b/kanta/kanta.py index a7d9485..8d93960 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -313,31 +313,6 @@ class Kanta(Generic[T]): return _register return _register(fn) - def logheader(self, fn=None): - """Register a transaction log header callback. - - Can be used as ``@kanta.logheader``. The callback composes the header - line printed before a transaction diff from the parts it declares: - ``action: str``, ``user: str`` and ``extra: str``. Kanta applies its - header colors to the parts before calling the callback, and a missing - ``user``/``extra`` is passed as an empty string, so callbacks only - arrange text ā€” no color codes, fallbacks, or padding. ``DictPre``/ - ``DictPost`` state dicts and the ``Kanta`` instance can also be - injected. The callback must be synchronous and return ``str`` (or - ``None`` to fall through to the next callback, then to the default - header). - - If registered, this replaces the default ``action by user`` header. - """ - - def _register(callback): - self._impl.add_logheader(callback) - return callback - - if fn is None: - return _register - return _register(fn) - def transaction( self, action: str, @@ -355,9 +330,8 @@ class Kanta(Generic[T]): the log header. Register a ``@kanta.logfmt`` callback to format the user value; the path ``"$user"`` is passed for this case. extra: Optional display-only string appended after the action in - the log header (colored by Kanta), or passed to a registered - ``@kanta.logheader`` callback. It is never persisted in the - change record. + the log header (colored by Kanta). It is never persisted in + the change record. mtime: Controls the modification time ``m``. ``True`` (default) sets ``m`` to the current UTC time. ``False`` omits ``m`` so the previous modification time remains in effect; this is used for diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index a2f2682..7596c8c 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -6,20 +6,13 @@ import asyncio import copy import importlib import logging -from collections.abc import Callable from datetime import UTC, datetime from types import SimpleNamespace 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, - bootstrap_logger, - colorize_header_parts, - 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 @@ -87,42 +80,6 @@ class KantaImpl(PersistenceMixin, Generic[T]): """Register one migration logging callback.""" self.callback_registry.register("logmigr", callback) - def add_logheader(self, callback) -> None: - """Register one transaction header formatting callback.""" - self.callback_registry.register("logheader", callback) - - def build_headerfmt( - self, - action: str, - user: str | None, - extra: str | None, - previous: dict | None, - current: dict | None, - ) -> Callable[..., str | None] | None: - """Build a headerfmt callable for ``log_change``. - - The logheader callbacks receive the header parts with Kanta's colors - already applied (missing user/extra as empty strings). Returns - ``None`` when no logheader callback is registered. - """ - if not self.callback_registry.has("logheader"): - return None - action_str, user_str, extra_str = colorize_header_parts(action, user, extra) - ctx = InjectionContext( - action=action_str, - user=user_str, - extra=extra_str, - previous_state=previous, - current_state=current, - kanta=self._kanta, - ) - registry = self.callback_registry - - def headerfmt(action: str, user: str, extra: str) -> str | None: - return registry.resolve_logheader(ctx) - - return headerfmt - async def _handle_migration_log( self, migration_result: MigrationResult, @@ -352,16 +309,12 @@ class KantaImpl(PersistenceMixin, Generic[T]): resolved = logfmt(formatted_user, _USER_PATH) if resolved is not None: formatted_user = resolved - headerfmt = self.build_headerfmt( - self.bootstrap_action, formatted_user, None, {}, current - ) log_change( self.bootstrap_action, record.diff, formatted_user, previous={}, logfmt=logfmt, - headerfmt=headerfmt, logger=logger, level=logging.INFO, ) diff --git a/kanta/logging.py b/kanta/logging.py index 10f4cc3..ed77125 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -303,7 +303,6 @@ def log_change( previous: dict | None = None, extra: str | None = None, logfmt: Callable[[Any, str], str | None] | None = None, - headerfmt: Callable[[str, str, str], str | None] | None = None, *, logger: logging.Logger = transaction_logger, level: int = logging.INFO, @@ -318,11 +317,8 @@ def log_change( user: Optional already-formatted user name to show in the header. previous: The previous state dict (for determining add vs update). extra: Optional display-only string appended after the action in the - default header (colored by Kanta), or passed to ``headerfmt``. + header (colored by Kanta). logfmt: Optional formatter callable ``(value, path) -> str | None``. - headerfmt: Optional header formatter callable receiving the - pre-colored ``(action, user, extra)`` parts and returning the - header line. Returning ``None`` falls back to the default header. logger: Logger to write to. Defaults to the ``kanta.transaction`` logger. level: Log level to use. Defaults to ``logging.INFO``. log_header: Whether to emit the header line. @@ -330,10 +326,7 @@ def log_change( """ header: str | None = None if log_header: - if headerfmt is not None: - header = headerfmt(action, user, extra) - if header is None: - header = format_action_header(action, user, extra) + header = format_action_header(action, user, extra) diff_lines = format_diff(diff, previous, logfmt) if log_diff else [] diff --git a/kanta/transaction.py b/kanta/transaction.py index f0de37e..3c49399 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -94,9 +94,6 @@ def transaction( if isinstance(log, logging.Logger) else transaction_logger ) - headerfmt = impl.build_headerfmt( - action, formatted_user, extra, previous, new_dict - ) log_change( action, record.diff, @@ -104,7 +101,6 @@ def transaction( previous, extra=extra, logfmt=logfmt, - headerfmt=headerfmt, logger=logger, log_header=log_header, log_diff=log_diff, diff --git a/tests/test_logging.py b/tests/test_logging.py index ad9e8d8..562a01a 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -80,30 +80,6 @@ def test_log_change_appends_extra_string(capsys): assert f"{_TARGET}mydb.db{_RESET}" in captured.err -def test_log_change_headerfmt_replaces_header(capsys): - kanta_logger = logging.getLogger("kanta") - kanta_logger.handlers.clear() - configure_logging() - log_change( - "update", - {}, - headerfmt=lambda action, user, extra: f"CUSTOM {action} {extra}", - extra="7", - ) - captured = capsys.readouterr() - assert "CUSTOM update 7" in captured.err - - -def test_log_change_headerfmt_none_falls_back(capsys): - kanta_logger = logging.getLogger("kanta") - kanta_logger.handlers.clear() - configure_logging() - log_change("update", {}, user="alice", headerfmt=lambda *args: None) - captured = capsys.readouterr() - assert "update" in captured.err - assert "alice" in captured.err - - def test_log_change_log_diff_false(capsys): kanta_logger = logging.getLogger("kanta") kanta_logger.handlers.clear() diff --git a/tests/test_logheader.py b/tests/test_logheader.py deleted file mode 100644 index bdbb6ca..0000000 --- a/tests/test_logheader.py +++ /dev/null @@ -1,275 +0,0 @@ -import logging - -import pytest - -from kanta import Kanta -from kanta.callbacks import DictPost, DictPre -from kanta.logging import _ACTION, _RESET, _TARGET, _USER, configure_logging - -from .support import Data, make_kanta, read_changes - - -@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_logheader_rejects_async(tmp_path, format_config): - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - with pytest.raises(TypeError, match="must not be async"): - - @kanta.logheader - async def header(action: str) -> str: - return action - - -def test_logheader_rejects_bad_return_annotation(tmp_path, format_config): - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - with pytest.raises(TypeError, match="must return"): - - @kanta.logheader - def header(action: str) -> int: - return 1 - - -def test_logheader_rejects_unknown_annotation(tmp_path, format_config): - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - with pytest.raises(TypeError, match="unsupported annotation"): - - @kanta.logheader - def header(action: str, bogus: int) -> str: - return action - - -def test_logheader_rejects_dict_extra(tmp_path, format_config): - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - with pytest.raises(TypeError, match="unsupported annotation"): - - @kanta.logheader - def header(action: str, extra: dict) -> str: - return action - - -@pytest.mark.asyncio -async def test_logheader_replaces_default_header(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def header(action: str, user: str, extra: str) -> str: - return f"{user} {action} {extra}" - - await kanta.open(log=False) - with kanta.transaction(action="update", user="alice", extra="tgt") as data: - data.counter = 1 - await kanta.close() - - # caplog strips ANSI codes; the colors are verified via capsys below. - assert "alice update tgt" in caplog.text - # The diff body is still logged after the custom header. - assert "counter" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_parts_are_colored_by_kanta(tmp_path, format_config, capsys): - logging.getLogger("kanta").handlers.clear() - configure_logging() - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def header(action: str, user: str, extra: str) -> str: - return f"{user} {action} {extra}" - - await kanta.open(log=False) - with kanta.transaction(action="update", user="alice", extra="tgt") as data: - data.counter = 1 - await kanta.close() - - err = capsys.readouterr().err - assert f"{_USER}alice{_RESET}" in err - assert f"{_ACTION}update{_RESET}" in err - assert f"{_TARGET}tgt{_RESET}" in err - - -@pytest.mark.asyncio -async def test_logheader_missing_user_and_extra_are_empty( - tmp_path, format_config, caplog -): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def header(action: str, user: str, extra: str) -> str: - return f"<{user}><{extra}>" - - await kanta.open(log=False) - with kanta.transaction(action="update") as data: - data.counter = 1 - await kanta.close() - - assert "<><>" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_injects_states_and_kanta(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def header( - action: str, - previous: DictPre, - current: DictPost, - kanta: Kanta, - ) -> str: - return ( - f"counter {previous.get('counter')}" - f" -> {current.get('counter')} db={kanta.filename.name}" - ) - - await kanta.open(log=False) - with kanta.transaction(action="increment") as data: - data.counter = 5 - await kanta.close() - - assert "counter 0 -> 5 db=test.db" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_chain_first_non_none_wins(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def first(action: str) -> str | None: - return None - - @kanta.logheader - def second(action: str, extra: str) -> str: - return f"SECOND {extra}" - - await kanta.open(log=False) - with kanta.transaction(action="update", extra="marked") as data: - data.counter = 1 - await kanta.close() - - assert "SECOND marked" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_all_none_falls_back_to_default( - tmp_path, format_config, caplog -): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def header(action: str) -> str | None: - return None - - await kanta.open(log=False) - with kanta.transaction(action="update", user="alice") as data: - data.counter = 1 - await kanta.close() - - assert "update" in caplog.text - assert "alice" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_receives_formatted_user(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logfmt(path="$user") - def resolve_user(value: str) -> str | None: - return "Alice" - - @kanta.logheader - def header(action: str, user: str) -> str: - return f"actor={user}" - - await kanta.open(log=False) - with kanta.transaction(action="update", user="uuid-1") as data: - data.counter = 1 - await kanta.close() - - assert "actor=Alice" in caplog.text - - -@pytest.mark.asyncio -async def test_logheader_applies_to_bootstrap(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.bootstrap") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - @kanta.logheader - def header(action: str) -> str: - return f"BOOT {action}" - - await kanta.open() - await kanta.close() - - assert "BOOT bootstrap" in caplog.text - - -@pytest.mark.asyncio -async def test_transaction_extra_string_in_default_header( - tmp_path, format_config, caplog -): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - await kanta.open(log=False) - with kanta.transaction(action="export", extra="mydb.db") as data: - data.counter = 1 - await kanta.close() - - assert "export" in caplog.text - assert "mydb.db" in caplog.text - - -@pytest.mark.asyncio -async def test_extra_is_not_persisted(tmp_path, format_config): - path = tmp_path / "test.db" - kanta = make_kanta(path, Data, format_config) - - await kanta.open(log=False) - with kanta.transaction(action="update", user="alice", extra="session-3") as data: - data.counter = 1 - await kanta.close() - - record = read_changes(path, format_config)[-1] - assert record.a == "update" - assert record.u == "alice" - - -@pytest.mark.asyncio -async def test_transaction_log_dict_toggles(tmp_path, format_config, caplog): - caplog.set_level(logging.INFO, logger="kanta.transaction") - kanta = make_kanta(tmp_path / "test.db", Data, format_config) - - await kanta.open(log=False) - with kanta.transaction( - action="myaction", log={"header": True, "diff": False} - ) as data: - data.counter = 1 - with kanta.transaction( - action="otheraction", log={"header": False, "diff": True} - ) as data: - data.counter = 2 - await kanta.close() - - # First transaction: header only. - assert "myaction" in caplog.text - # Second transaction: diff only, no header. - assert "otheraction" not in caplog.text - assert "counter" in caplog.text -- 2.55.0 From e42f81f44f8bbbc9b274a130ca50e2dfe6aaeeb3 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 01:26:50 +0000 Subject: [PATCH 13/24] Replace log dict toggles with logdiff kwarg and kanta.transaction.diff logger Per-transaction logdiff=False skips building and printing the diff body, logging only the header. Globally, configure_logging(diff=False) disables the kanta.transaction.diff child logger, which now carries all diff lines, so applications can route or silence diffs separately from headers. --- demo/main.py | 94 +++++++++++++-------------------- docs/database.md | 8 ++- kanta/kanta.py | 13 +++-- kanta/logging.py | 44 ++++++++------- kanta/transaction.py | 20 +++---- tests/test_kanta_integration.py | 20 +++++++ tests/test_logging.py | 43 +++++++++------ 7 files changed, 132 insertions(+), 110 deletions(-) diff --git a/demo/main.py b/demo/main.py index 6baad27..3d3d9cc 100644 --- a/demo/main.py +++ b/demo/main.py @@ -1,15 +1,5 @@ -"""Kanta feature demo. - -Run from the project root: python demo/main.py - -Demonstrates bootstrap, colored transaction diffs, logfmt value formatting, -logging toggles, rollback, migrations, and a custom clock. -The database is recreated with fixed timestamps on every run; everything else -lives in this file. -""" - +#!/usr/bin/env -S uv run import asyncio -import logging import sys from datetime import UTC, datetime, timedelta from pathlib import Path @@ -38,34 +28,24 @@ kanta_v0 = Kanta(filename, Data()) @kanta_v0.bootstrap def bootstrap(data: Data) -> None: """Create the initial admin user.""" - data.users["u1"] = {"name": "Alice", "role": "admin"} + data.users["userid001"] = {"name": "Alice", "role": "admin"} -# Redefinition to simulate new version with counter renamed to total +# Redefinition to simulate new version class Data(msgspec.Struct): users: dict[str, dict] = {} - total: int = 0 + total: int = 0 # Replaces old counter field + lang: str = "en" # New field def migrate_v1(d: dict) -> None: """Rename counter to total""" - d["total"] = d.pop("counter") + d["total"] = d["counter"] kanta_v1 = Kanta(filename, Data(), migrations=sys.modules[__name__]) -_now = datetime(2027, 1, 1, tzinfo=UTC) - - -@kanta_v0.clock -@kanta_v1.clock -def fake_clock() -> datetime: - global _now - _now += timedelta(hours=1) - return _now - - @kanta_v0.logfmt @kanta_v1.logfmt def resolve_user( @@ -82,61 +62,61 @@ def resolve_user( return None -def section(title: str) -> None: - print(f"\n# {title}", flush=True) - - async def main() -> None: filename.unlink(missing_ok=True) - section("Database creation with v0 schema and basic access") + print("# Database creation with v0 schema and basic ops, pretty logs", flush=True) # Open and close automatically; you can also `await kanta.open()` instead async with kanta_v0 as kanta: - with kanta.transaction(action="create", user="u2") as data: - data.users["u2"] = {"name": "Bob", "role": "user"} + with kanta.transaction(action="create", user="userid001") as data: + data.users["userid002"] = {"name": "Bob", "role": "user"} - with kanta.transaction(action="update", user="u1") as data: - data.users["u2"]["role"] = "editor" + with kanta.transaction(action="update", user="userid001") as data: + data.users["userid002"]["role"] = "editor" data.counter = 1 - with kanta.transaction(action="delete", user="u1") as data: - del data.users["u2"] + with kanta.transaction(action="delete", user="userid002") as data: + del data.users["userid001"] # Display-only extra string, appended after the action. - with kanta.transaction(action="export", user="u1", extra=filename.name) as data: + with kanta.transaction( + action="export", user="userid002", extra="extra info" + ) as data: data.counter = 2 - # Compact logging, diff only: a system fix stamped by the clock, but the - # modification time (m) is not updated. - with kanta.transaction( - action="repair", mtime=False, log={"header": False, "diff": True} - ) as data: - data.users["u3"] = {"name": "Carol", "role": "user"} - - # A failing transaction rolls back and logs a warning. try: - with kanta.transaction(action="reset", user="u1") as data: + with kanta.transaction(action="reset") as data: data.counter = 99 raise ValueError("simulated failure") except ValueError: - pass + print(f"# Reading does not need transaction: {data.counter=}", flush=True) - # Compact logging, header only. - with kanta.transaction( - action="import", user="u1", log={"header": True, "diff": False} - ) as data: + with kanta.transaction(action="import", logdiff=False) as data: data.counter = 3 - section("A later version of our application with new data model and migrations") + print( + "\n# A later version of our application with new data model and migrations", + flush=True, + ) async with kanta_v1 as kanta: - with kanta.transaction(action="update", user="u1", extra=filename.name) as data: + with kanta.transaction( + action="update", user="userid002", extra=filename.name + ) as data: data.total = 4 - with kanta.transaction(action="create", user="u3", extra="Dave (u4)") as data: - data.users["u4"] = {"name": "Dave", "role": "user"} + +# Fake clock for deterministic timestamps +_now = datetime(2027, 1, 1, tzinfo=UTC) + + +@kanta_v0.clock +@kanta_v1.clock +def fake_clock() -> datetime: + global _now + _now += timedelta(hours=1) + return _now if __name__ == "__main__": configure_logging() - logging.getLogger("kanta").setLevel(logging.DEBUG) # show migration diffs asyncio.run(main()) diff --git a/docs/database.md b/docs/database.md index 99ec5ca..410b88d 100644 --- a/docs/database.md +++ b/docs/database.md @@ -215,8 +215,12 @@ def resolve_user_key(value: str) -> str | None: - `kanta.transaction(..., extra="...")` accepts a display-only string that is appended after the action in the header (colored by Kanta); it is never persisted in the `ChangeRecord`. -- The header and diff parts can be toggled independently per transaction: - `kanta.transaction(..., log={"header": True, "diff": False})`. +- `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. ## Migrations diff --git a/kanta/kanta.py b/kanta/kanta.py index 8d93960..d2d6e6f 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -320,7 +320,8 @@ class Kanta(Generic[T]): user: str | None = None, extra: str | None = None, mtime: bool | datetime = True, - log: bool | logging.Logger | dict[str, bool] = True, + log: bool | logging.Logger = True, + logdiff: bool = True, ): """Create a transactional mutation context manager. @@ -341,9 +342,12 @@ class Kanta(Generic[T]): log: Controls transaction logging. ``True`` (default) uses the ``kanta.transaction`` logger. ``False`` suppresses the transaction log. A :class:`~logging.Logger` instance writes - output to that logger instead. A dict such as - ``{"header": True, "diff": False}`` toggles the header and - diff parts independently. + output to that logger instead. + logdiff: Whether to build and print the diff body. ``False`` + skips diff formatting entirely 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)``. Returns: A context manager yielding the live state object for mutation. @@ -360,4 +364,5 @@ class Kanta(Generic[T]): extra=extra, mtime=mtime, log=log, + logdiff=logdiff, ) diff --git a/kanta/logging.py b/kanta/logging.py index ed77125..c25de56 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -306,7 +306,6 @@ def log_change( *, logger: logging.Logger = transaction_logger, level: int = logging.INFO, - log_header: bool = True, log_diff: bool = True, ) -> None: """Log a database change with pretty-printed diff. @@ -321,30 +320,33 @@ def log_change( logfmt: Optional formatter callable ``(value, path) -> str | None``. logger: Logger to write to. Defaults to the ``kanta.transaction`` logger. level: Log level to use. Defaults to ``logging.INFO``. - log_header: Whether to emit the header line. - log_diff: Whether to emit the diff lines. + log_diff: Whether to build and emit the diff lines. ``False`` skips + diff formatting entirely and only the header is logged. + + Diff lines are emitted on the ``.diff`` child logger, so they + can be silenced globally without losing the headers (see + :func:`configure_logging`). When the child logger would not emit at the + given level, diff formatting is skipped altogether. """ - header: str | None = None - if log_header: - header = format_action_header(action, user, extra) - - diff_lines = format_diff(diff, previous, logfmt) if log_diff else [] - - if header is None: - for line in diff_lines: - logger.log(level, line) - return + diff_logger = logging.getLogger(f"{logger.name}.diff") + diff_lines = ( + format_diff(diff, previous, logfmt) + if log_diff and diff_logger.isEnabledFor(level) + else [] + ) + header = format_action_header(action, user, extra) if not diff_lines: logger.log(level, header) return if len(diff_lines) == 1: - logger.log(level, f"{header}{diff_lines[0]}") - else: - logger.log(level, header) - for line in diff_lines: - logger.log(level, line) + diff_logger.log(level, f"{header}{diff_lines[0]}") + return + + logger.log(level, header) + for line in diff_lines: + diff_logger.log(level, line) def configure_logging( @@ -353,6 +355,7 @@ def configure_logging( bootstrap: bool = True, migration: bool = True, transaction: bool = True, + diff: bool = True, ) -> None: """Configure Kanta's default logging output. @@ -366,11 +369,16 @@ def configure_logging( bootstrap: Whether bootstrap logs are enabled. migration: Whether migration logs are enabled. transaction: Whether transaction logs are enabled. + diff: Whether transaction diff lines are enabled. When ``False``, + only transaction headers are printed and diff formatting is + skipped. Per transaction this is controlled by the ``logdiff`` + argument of :meth:`Kanta.transaction`. This helper is not called automatically; applications that want Kanta's default output can call it, but most applications will configure logging themselves. """ + logging.getLogger("kanta.transaction.diff").disabled = not diff for name, enabled in ( ("kanta.bootstrap", bootstrap), ("kanta.migration", migration), diff --git a/kanta/transaction.py b/kanta/transaction.py index 3c49399..a211968 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -23,7 +23,8 @@ def transaction( user: str | None = None, extra: str | None = None, mtime: bool | datetime = True, - log: bool | logging.Logger | dict[str, bool] = True, + log: bool | logging.Logger = True, + logdiff: bool = True, ): """Wrap writes in a transaction and yield the live db object.""" if impl.readonly: @@ -83,17 +84,9 @@ def transaction( if resolved is not None: formatted_user = resolved if log is not False: - if isinstance(log, dict): - log_header = bool(log.get("header", True)) - log_diff = bool(log.get("diff", True)) - logger = transaction_logger - else: - log_header = log_diff = True - logger = ( - log - if isinstance(log, logging.Logger) - else transaction_logger - ) + logger = ( + log if isinstance(log, logging.Logger) else transaction_logger + ) log_change( action, record.diff, @@ -102,8 +95,7 @@ def transaction( extra=extra, logfmt=logfmt, logger=logger, - log_header=log_header, - log_diff=log_diff, + log_diff=logdiff, ) except Exception: _logger.warning("Transaction '%s' failed, rolling back changes", action) diff --git a/tests/test_kanta_integration.py b/tests/test_kanta_integration.py index 94f97ba..46b2ad1 100644 --- a/tests/test_kanta_integration.py +++ b/tests/test_kanta_integration.py @@ -738,6 +738,26 @@ async def test_transaction_log_false_suppresses_log(tmp_path, format_config, cap assert not info_messages +@pytest.mark.asyncio +async def test_transaction_logdiff_false_logs_header_only( + tmp_path, format_config, caplog +): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + await kanta.open() + + with caplog.at_level(logging.INFO, logger="kanta.transaction"): + with kanta.transaction(action="inc", logdiff=False) as data: + data.counter = 1 + + await kanta.close() + + messages = [r.message for r in caplog.records if r.levelno == logging.INFO] + assert len(messages) == 1 + assert "inc" in messages[0] + assert "counter" not in messages[0] + + @pytest.mark.asyncio async def test_transaction_log_custom_logger(tmp_path, format_config, caplog): path = tmp_path / "test.db" diff --git a/tests/test_logging.py b/tests/test_logging.py index 562a01a..901ecdc 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -30,10 +30,17 @@ def test_colorize_header_parts_missing_user_and_extra(): @pytest.fixture(autouse=True) def _reset_kanta_loggers(): yield - for name in ("kanta", "kanta.transaction", "kanta.bootstrap", "kanta.migration"): + for name in ( + "kanta", + "kanta.transaction", + "kanta.transaction.diff", + "kanta.bootstrap", + "kanta.migration", + ): logger = logging.getLogger(name) logger.setLevel(logging.NOTSET) logger.propagate = True + logger.disabled = False logger.handlers.clear() @@ -80,30 +87,36 @@ def test_log_change_appends_extra_string(capsys): assert f"{_TARGET}mydb.db{_RESET}" in captured.err -def test_log_change_log_diff_false(capsys): +def test_log_change_log_diff_false(capsys, monkeypatch): kanta_logger = logging.getLogger("kanta") kanta_logger.handlers.clear() configure_logging() + + def _boom(*args, **kwargs): + raise AssertionError("format_diff should not be called") + + monkeypatch.setattr("kanta.logging.format_diff", _boom) log_change("update", {"counter": 5}, previous={}, log_diff=False) captured = capsys.readouterr() assert "update" in captured.err assert "counter" not in captured.err -def test_log_change_log_header_false(capsys): +def test_configure_logging_diff_false(capsys): kanta_logger = logging.getLogger("kanta") kanta_logger.handlers.clear() - configure_logging() - log_change("update", {"counter": 5}, previous={}, log_header=False) + configure_logging(diff=False) + log_change("update", {"counter": 5}, previous={}) + captured = capsys.readouterr() + assert "update" in captured.err + assert "counter" not in captured.err + + +def test_configure_logging_diff_true_reenables(capsys): + kanta_logger = logging.getLogger("kanta") + kanta_logger.handlers.clear() + configure_logging(diff=False) + configure_logging(diff=True) + log_change("update", {"counter": 5}, previous={}) captured = capsys.readouterr() - assert "update" not in captured.err assert "counter" in captured.err - - -def test_log_change_both_disabled_logs_nothing(capsys): - kanta_logger = logging.getLogger("kanta") - kanta_logger.handlers.clear() - configure_logging() - log_change("update", {"counter": 5}, previous={}, log_header=False, log_diff=False) - captured = capsys.readouterr() - assert captured.err == "" -- 2.55.0 From 6eb90878634c61f4af7fb3656664c2808161e014 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:11:54 +0000 Subject: [PATCH 14/24] Add logemit event callbacks and kanta.tty terminal formatting All change-related output (transactions, bootstrap, migrations) is now described by a mutable LogEvent carrying full state plus the preferred logger and level, and dispatched through emit_event. @kanta.logemit callbacks receive the event and decide what is logged where: falsy return marks it handled, truthy passes it (possibly modified) down the chain, with default_emit - Kanta's own formatting, now just another emitter - as the fallback. Pretty header and diff lines are lazy event properties. New kanta.tty module: Line builder (call to append content, .colorname arms a palette color for the next call with automatic folded reset, width/align padding), a mutable Colors palette storing bare SGR params (0 clears, sequential last-wins stacking), and strip_ansi/displaywidth/pad helpers that count wide chars and emoji correctly. --- demo/main.py | 7 +- docs/database.md | 48 +++++++ kanta/callbacks.py | 16 +++ kanta/kanta.py | 24 ++++ kanta/kantaimpl.py | 73 +++++++---- kanta/logging.py | 259 +++++++++++++++++++++++++------------- kanta/transaction.py | 25 ++-- kanta/tty.py | 181 ++++++++++++++++++++++++++ tests/test_format_diff.py | 6 +- tests/test_logemit.py | 157 +++++++++++++++++++++++ tests/test_logging.py | 26 ++-- tests/test_tty.py | 74 +++++++++++ 12 files changed, 758 insertions(+), 138 deletions(-) create mode 100644 kanta/tty.py create mode 100644 tests/test_logemit.py create mode 100644 tests/test_tty.py diff --git a/demo/main.py b/demo/main.py index 3d3d9cc..6a7282b 100644 --- a/demo/main.py +++ b/demo/main.py @@ -65,7 +65,7 @@ def resolve_user( async def main() -> None: filename.unlink(missing_ok=True) - print("# Database creation with v0 schema and basic ops, pretty logs", flush=True) + print("# Database creation with v0 schema and basic ops, pretty logs") # Open and close automatically; you can also `await kanta.open()` instead async with kanta_v0 as kanta: with kanta.transaction(action="create", user="userid001") as data: @@ -94,10 +94,7 @@ async def main() -> None: with kanta.transaction(action="import", logdiff=False) as data: data.counter = 3 - print( - "\n# A later version of our application with new data model and migrations", - flush=True, - ) + print("\n# A later version of our application with new data model and migrations") async with kanta_v1 as kanta: with kanta.transaction( action="update", user="userid002", extra=filename.name diff --git a/docs/database.md b/docs/database.md index 410b88d..2b6be26 100644 --- a/docs/database.md +++ b/docs/database.md @@ -222,6 +222,54 @@ def resolve_user_key(value: str) -> str | None: `kanta.transaction.diff` child logger so applications can route or silence them separately from the headers. +#### Log Emitters + +- Every change-related message Kanta emits (transaction/bootstrap/migration + changes, `Created `, migration summaries) is described by a + `kanta.logging.LogEvent` and dispatched through `kanta.logging.emit_event`. + Kanta's own output goes through the same mechanism: when no `logemit` + callback handles an event, `kanta.logging.default_emit` renders it with the + built-in formatting. +- A `LogEvent` carries the event `kind` (`"change"`, `"created"`, + `"migrated"`), the preferred `logger` and `level`, and all relevant state: + `action`, `user`, `extra`, `diff`, `previous`/`current` state dicts, the + built `logfmt` chain, and version info for migration events. Pretty + `header` and `diff_lines` are lazy properties, built only if accessed. +- `@kanta.logemit` registers a callback receiving the event. The callback + decides what is logged and where: it may log one or more messages on + `event.logger`, log somewhere else, or nothing at all. A falsy return + value marks the event handled and stops the chain; a truthy return value + passes the event ā€” possibly modified ā€” to the next registered callback. + When all callbacks pass, `default_emit` renders the event; a callback may + also call `default_emit(event)` itself to delegate events it does not + customize. Operational diagnostics (rollback warnings, integrity errors) + do not go through this mechanism. + +```python +@kanta.logemit +def emit(ev: LogEvent): + if ev.kind != "change": + return default_emit(ev) # delegate, no chaining needed + actor = ev.current.get("users", {}).get(ev.user, {}).get("name", ev.user) + line = Line().user(actor, width=20)(" ").action(ev.action) + ev.logger.log(ev.level, f"{line}\n" + "\n".join(ev.diff_lines)) +``` + +#### Terminal Formatting Helpers + +- `kanta.tty` provides the building blocks used by Kanta's own rendering: + - `colors`: the mutable color palette. Colors are bare SGR parameter + strings (e.g. `"1;34"`, `"38;5;226"`) without escape framing. Attributes + are read at render time, so assignments (`colors.action = "36"`) and + additions (`colors.session = "38;5;226"`) take effect immediately. + - `Line`: builds a terminal string part by part. Calling it appends + content (`str`-converted); `.` arms a palette color for the + next call only, and the reset is folded into a single escape sequence + with whatever color comes next. `width=`/`align=` pad by display width; + `str(line)` finishes the line and restores default colors. + - `strip_ansi`, `displaywidth` (wide chars and emoji count correctly) and + `pad` for working with pre-colored strings. + ## Migrations - Migration source is configured on `Kanta(...)` via `migrations=`. diff --git a/kanta/callbacks.py b/kanta/callbacks.py index 0155a1e..126b467 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -103,6 +103,7 @@ class CallbackRegistry: "logmigr": [], } self._logfmt_callbacks: list[_LogFmtFunctionSpec | _LogFmtClassSpec] = [] + self._logemit_callbacks: list[Callable[..., Any]] = [] def register( self, @@ -123,6 +124,14 @@ class CallbackRegistry: ) return callback + if kind == "logemit": + if inspect.isclass(callback) or not callable(callback): + raise TypeError("logemit callbacks must be functions") + if inspect.iscoroutinefunction(callback): + raise TypeError("logemit callbacks must not be async") + self._logemit_callbacks.append(callback) + return callback + if kind not in self._callbacks: raise ValueError(f"unknown callback kind: {kind}") @@ -175,8 +184,15 @@ class CallbackRegistry: """Return True if any callback of *kind* is registered.""" if kind == "logfmt": return bool(self._logfmt_callbacks) + if kind == "logemit": + return bool(self._logemit_callbacks) return bool(self._callbacks[kind]) + @property + def logemit_handlers(self) -> list[Callable[..., Any]]: + """Registered logemit callbacks in registration order.""" + return self._logemit_callbacks + def build_logfmt(self, ctx: InjectionContext) -> Callable[[Any, str], str | None]: """Build a chained formatter from registered logfmt callbacks.""" formatters: list[tuple[Callable[[Any, str], str | None], str | None]] = [] diff --git a/kanta/kanta.py b/kanta/kanta.py index d2d6e6f..3c42a71 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -313,6 +313,30 @@ class Kanta(Generic[T]): return _register return _register(fn) + def logemit(self, fn=None): + """Register a log emitter callback. + + Can be used as ``@kanta.logemit``. The callback receives a single + :class:`kanta.logging.LogEvent` describing the event, including the + preferred logger and level, and decides what (if anything) is logged + and where. + + A falsy return value marks the event as handled and stops the chain. + A truthy return value passes the event ā€” possibly modified ā€” to the + next registered callback; when all callbacks pass, Kanta renders the + event with its built-in formatting + (:func:`kanta.logging.default_emit`), which a callback may also call + itself to delegate events it does not care about. + """ + + def _register(callback): + self._impl.add_logemit(callback) + return callback + + if fn is None: + return _register + return _register(fn) + def transaction( self, action: str, diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index 7596c8c..082e38d 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -12,7 +12,13 @@ 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, bootstrap_logger, log_change, migration_logger +from kanta.logging import ( + _USER_PATH, + LogEvent, + bootstrap_logger, + emit_event, + migration_logger, +) from kanta.migrations import MigrationResult, Migrations from kanta.persistence import PersistenceMixin from kanta.serialization import restore_data_in_place, struct_to_dict @@ -80,6 +86,10 @@ class KantaImpl(PersistenceMixin, Generic[T]): """Register one migration logging callback.""" self.callback_registry.register("logmigr", callback) + def add_logemit(self, callback) -> None: + """Register one log emitter callback.""" + self.callback_registry.register("logemit", callback) + async def _handle_migration_log( self, migration_result: MigrationResult, @@ -110,21 +120,29 @@ class KantaImpl(PersistenceMixin, Generic[T]): for info in changed: if info.diff: - log_change( - info.name, - info.diff, - previous=info.before, - logger=migration_log, - level=logging.DEBUG, + emit_event( + LogEvent( + kind="change", + logger=migration_log, + level=logging.DEBUG, + action=info.name, + diff=info.diff, + previous=info.before, + ), + self.callback_registry.logemit_handlers, ) descriptions = [f"{m.name} ({m.description})" for m in changed] - migration_log.info( - "Migrated %s v%s -> v%s: %s", - self.filename, - previous_version, - migration_result.version, - ", ".join(descriptions), + emit_event( + LogEvent( + kind="migrated", + logger=migration_log, + filename=str(self.filename), + from_version=previous_version, + to_version=migration_result.version, + migrations=descriptions, + ), + self.callback_registry.logemit_handlers, ) async def open( @@ -296,7 +314,14 @@ class KantaImpl(PersistenceMixin, Generic[T]): logger = ( log if isinstance(log, logging.Logger) else bootstrap_logger ) - logger.info("Created %s", self.filename.resolve()) + emit_event( + LogEvent( + kind="created", + logger=logger, + filename=str(self.filename.resolve()), + ), + self.callback_registry.logemit_handlers, + ) logfmt = self.callback_registry.build_logfmt( InjectionContext( previous_state={}, @@ -309,14 +334,18 @@ class KantaImpl(PersistenceMixin, Generic[T]): 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, + emit_event( + LogEvent( + kind="change", + logger=logger, + action=self.bootstrap_action, + user=formatted_user, + diff=record.diff, + previous={}, + current=current, + logfmt=logfmt, + ), + self.callback_registry.logemit_handlers, ) except Exception: self.opened = False diff --git a/kanta/logging.py b/kanta/logging.py index c25de56..5f29db2 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -1,20 +1,28 @@ """Database change logging with pretty-printed diffs. -Provides loggers for JSONL database changes, bootstrap events, and -migrations. Diff output is formatted in a human-readable path notation -style with color coding. +All change-related output is described by a :class:`LogEvent` and dispatched +through :func:`emit_event`, which runs any registered ``logemit`` callbacks +and falls back to :func:`default_emit` for the built-in formatting. Diff +output is formatted in a human-readable path notation style with color +coding; see :mod:`kanta.tty` for the color palette and line builder. """ import logging import re import sys -from collections.abc import Callable +from collections.abc import Callable, Iterable from typing import Any +import msgspec + +from kanta.tty import Line, displaywidth + transaction_logger = logging.getLogger("kanta.transaction") bootstrap_logger = logging.getLogger("kanta.bootstrap") migration_logger = logging.getLogger("kanta.migration") +_logger = logging.getLogger(__name__) + # Pattern to match control characters and bidirectional overrides _UNSAFE_CHARS = re.compile( r"[\x00-\x1f\x7f-\x9f" @@ -24,21 +32,119 @@ _UNSAFE_CHARS = re.compile( r"]" ) -# ANSI color codes -_RESET = "\033[0m" -_SEP = "\033[38;5;242m" # Dark grey for separators -_PATH_PREFIX = "\033[38;5;242m" # Dark grey for path prefix -_PATH_FINAL = "\033[38;5;250m" # Default for final element -_DELETE = "\033[1;31m" # Red for deletions -_ADD = "\033[0;32m" # Green for additions -_ACTION = "\033[1;34m" # Bold blue for action name -_USER = "\033[0;34m" # Blue for user display -_TARGET = "\033[38;5;250m" # White for the extra/target display - # Metadata path used when formatting the transaction actor. _USER_PATH = "$user" +class LogEvent(msgspec.Struct, kw_only=True): + """All state describing one loggable event, passed to logemit callbacks. + + ``kind`` is ``"change"`` (transaction, bootstrap, or migration diff), + ``"created"`` (database file created), or ``"migrated"`` (migration + summary). ``logger`` and ``level`` are Kanta's preferred destination; + a callback may use them, log elsewhere, or not log at all. + + The event is mutable: a callback may modify it before returning a truthy + value to pass it on, affecting later callbacks and the built-in fallback. + """ + + kind: str + logger: logging.Logger + level: int = logging.INFO + action: str | None = None + user: str | None = None + extra: str | None = None + diff: dict = msgspec.field(default_factory=dict) + previous: dict | None = None + current: dict | None = None + logfmt: Callable[[Any, str], str | None] | None = None + show_diff: bool = True + filename: str | None = None + from_version: int | None = None + to_version: int | None = None + migrations: list[str] = msgspec.field(default_factory=list) + _header: str | None = None + _diff_lines: list[str] | None = None + + @property + def header(self) -> str: + """The default header line (colored), built on first access.""" + if self._header is None: + self._header = format_action_header( + self.action or "", self.user, self.extra + ) + return self._header + + @property + def diff_lines(self) -> list[str]: + """Pretty-printed diff lines, built on first access and cached.""" + if self._diff_lines is None: + self._diff_lines = format_diff(self.diff, self.previous, self.logfmt) + return self._diff_lines + + +def emit_event( + ev: LogEvent, + handlers: Iterable[Callable[[LogEvent], Any]] = (), +) -> None: + """Dispatch *ev* through registered logemit handlers. + + Each handler receives the event and may log it (or not) as it sees fit. + A falsy return value stops the chain: the event is considered handled. + A truthy return value passes the event ā€” possibly modified ā€” to the next + handler. When all handlers pass, :func:`default_emit` renders the event + with the built-in formatting. + """ + for handler in handlers: + try: + proceed = handler(ev) + except Exception: + _logger.exception("logemit callback failed, using default formatting") + break + if not proceed: + return + default_emit(ev) + + +def default_emit(ev: LogEvent) -> None: + """Emit *ev* with Kanta's built-in formatting. + + This is what runs when no logemit callback handles the event; custom + callbacks may call it to delegate events they do not care about. + """ + if ev.kind == "created": + ev.logger.log(ev.level, "Created %s", ev.filename) + return + + if ev.kind == "migrated": + ev.logger.log( + ev.level, + "Migrated %s v%s -> v%s: %s", + ev.filename, + ev.from_version, + ev.to_version, + ", ".join(ev.migrations), + ) + return + + # kind == "change": diff lines go to the .diff child logger so + # they can be silenced or routed separately from the headers. + diff_logger = logging.getLogger(f"{ev.logger.name}.diff") + lines = ev.diff_lines if ev.show_diff and diff_logger.isEnabledFor(ev.level) else [] + + if not lines: + ev.logger.log(ev.level, ev.header) + return + + if len(lines) == 1: + diff_logger.log(ev.level, f"{ev.header}{lines[0]}") + return + + ev.logger.log(ev.level, ev.header) + for line in lines: + diff_logger.log(ev.level, line) + + def _join_path(path: str, key: str) -> str: """Append *key* to a dot-notation *path*.""" if not path: @@ -119,17 +225,20 @@ def _format_path_components( def _format_path( path: list[str], logfmt: Callable[[Any, str], str | None] | None, - final_color: str = _PATH_FINAL, + final_color: str = "path_final", ) -> str: - """Format a path as dot notation with prefix in dark grey, final colored.""" + """Format a path as dot notation with prefix in dark grey, final colored. + + *final_color* names a color in the :data:`kanta.tty.colors` palette. + """ components = _format_path_components(path, logfmt) if not components: return "" - if len(components) == 1: - return f"{final_color}{components[0]}{_RESET}" - prefix = ".".join(components[:-1]) - final = components[-1] - return f"{_PATH_PREFIX}{prefix}.{_RESET}{final_color}{final}{_RESET}" + line = Line() + if len(components) > 1: + line.path_prefix(".".join(components[:-1]) + ".") + getattr(line, final_color)(components[-1]) + return str(line) def _get_nested(data: dict | None, path: list[str]) -> Any: @@ -207,16 +316,16 @@ def _format_change_lines( """Format a single change as one or more lines.""" if change_type == "delete": components = _format_path_components(path, logfmt) - if len(components) == 1: - return [f" {_DELETE}{components[0]} āœ—{_RESET}"] - prefix = ".".join(components[:-1]) - final = components[-1] - return [f" {_PATH_PREFIX}{prefix}.{_RESET}{_DELETE}{final} āœ—{_RESET}"] + line = Line()(" ") + if len(components) > 1: + line.path_prefix(".".join(components[:-1]) + ".") + line.delete(components[-1], " āœ—") + return [str(line)] if change_type == "add": - path_str = _format_path(path, logfmt, final_color=_ADD) + path_str = _format_path(path, logfmt, final_color="add") if isinstance(value, dict) and value: - lines = [f" {path_str} {_SEP}={_RESET}"] + lines = [str(Line()(" ", path_str, " ").sep("="))] formatted_items = [] base_path = ".".join(path) for k, v in value.items(): @@ -224,18 +333,22 @@ def _format_change_lines( key_display = _format_value(k, key_path, max_len=30, logfmt=logfmt) v_str = _format_value(v, key_path, max_len=30, logfmt=logfmt) formatted_items.append((key_display, v_str)) - max_key_len = max(len(k) for k, _ in formatted_items) - field_width = max(max_key_len, 12) - for k_display, v_str in formatted_items: - padding = " " * (field_width - len(k_display)) - lines.append(f" {k_display}{_SEP}:{_RESET}{padding} {v_str}") - return lines + field_width = max(displaywidth(k) for k, _ in formatted_items) + field_width = max(field_width, 12) + return lines + [ + str( + Line()(" ", k).sep(":")( + " " * (field_width - displaywidth(k)), " ", v + ) + ) + for k, v in formatted_items + ] value_str = _format_value(value, ".".join(path), logfmt=logfmt) - return [f" {path_str} {_SEP}={_RESET} {value_str}"] + return [str(Line()(" ", path_str, " ").sep("=")(" ", value_str))] value_str = _format_value(value, ".".join(path), logfmt=logfmt) path_str = _format_path(path, logfmt=logfmt) - return [f" {path_str} {_SEP}={_RESET} {value_str}"] + return [str(Line()(" ", path_str, " ").sep("=")(" ", value_str))] def format_diff( @@ -265,35 +378,18 @@ def format_diff( return lines -def colorize_header_parts( - action: str, - user: str | None = None, - extra: str | None = None, -) -> tuple[str, str, str]: - """Apply Kanta's header colors to the action, user, and extra parts. - - ``None`` user/extra become empty strings so custom header callbacks can - interpolate the parts directly without fallbacks. - """ - action_str = f"{_ACTION}{action}{_RESET}" - user_str = f"{_USER}{user}{_RESET}" if user else "" - extra_str = f"{_TARGET}{extra}{_RESET}" if extra else "" - return action_str, user_str, extra_str - - def format_action_header( action: str, user: str | None = None, extra: str | None = None, ) -> str: """Format the default action header line.""" - action_str, user_str, extra_str = colorize_header_parts(action, user, extra) - header = action_str - if extra_str: - header = f"{header} {extra_str}" - if user_str: - header = f"{header} by {user_str}" - return header + line = Line().action(action) + if extra: + line(" ").target(extra) + if user: + line(" by ").user(user) + return str(line) def log_change( @@ -308,7 +404,11 @@ def log_change( level: int = logging.INFO, log_diff: bool = True, ) -> None: - """Log a database change with pretty-printed diff. + """Log a database change with the built-in formatting. + + Compatibility wrapper around :func:`default_emit`; Kanta itself builds a + :class:`LogEvent` and dispatches it through :func:`emit_event` so logemit + callbacks see it. Args: action: The action name (e.g., "login", "admin:delete_user"). @@ -322,31 +422,21 @@ def log_change( level: Log level to use. Defaults to ``logging.INFO``. log_diff: Whether to build and emit the diff lines. ``False`` skips diff formatting entirely and only the header is logged. - - Diff lines are emitted on the ``.diff`` child logger, so they - can be silenced globally without losing the headers (see - :func:`configure_logging`). When the child logger would not emit at the - given level, diff formatting is skipped altogether. """ - diff_logger = logging.getLogger(f"{logger.name}.diff") - diff_lines = ( - format_diff(diff, previous, logfmt) - if log_diff and diff_logger.isEnabledFor(level) - else [] + default_emit( + LogEvent( + kind="change", + logger=logger, + level=level, + action=action, + user=user, + extra=extra, + diff=diff, + previous=previous, + logfmt=logfmt, + show_diff=log_diff, + ) ) - header = format_action_header(action, user, extra) - - if not diff_lines: - logger.log(level, header) - return - - if len(diff_lines) == 1: - diff_logger.log(level, f"{header}{diff_lines[0]}") - return - - logger.log(level, header) - for line in diff_lines: - diff_logger.log(level, line) def configure_logging( @@ -379,6 +469,7 @@ def configure_logging( themselves. """ logging.getLogger("kanta.transaction.diff").disabled = not diff + for name, enabled in ( ("kanta.bootstrap", bootstrap), ("kanta.migration", migration), diff --git a/kanta/transaction.py b/kanta/transaction.py index a211968..3be160a 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, log_change, transaction_logger +from kanta.logging import _USER_PATH, LogEvent, emit_event, transaction_logger from kanta.serialization import restore_data_in_place, struct_to_dict _logger = logging.getLogger(__name__) @@ -87,15 +87,20 @@ def transaction( logger = ( log if isinstance(log, logging.Logger) else transaction_logger ) - log_change( - action, - record.diff, - formatted_user, - previous, - extra=extra, - logfmt=logfmt, - logger=logger, - log_diff=logdiff, + emit_event( + LogEvent( + kind="change", + logger=logger, + action=action, + user=formatted_user, + extra=extra, + diff=record.diff, + previous=previous, + current=new_dict, + logfmt=logfmt, + show_diff=logdiff, + ), + impl.callback_registry.logemit_handlers, ) except Exception: _logger.warning("Transaction '%s' failed, rolling back changes", action) diff --git a/kanta/tty.py b/kanta/tty.py new file mode 100644 index 0000000..b145fa9 --- /dev/null +++ b/kanta/tty.py @@ -0,0 +1,181 @@ +"""Terminal string building: ANSI colors, display widths, and a line builder. + +Colors are stored as bare SGR parameter strings (e.g. ``"1;34"``) without +the ``\\x1b[`` prefix and ``m`` suffix. The :class:`Line` builder understands +how SGR parameters stack: ``0`` clears everything, other parameters apply +sequentially and the last one of each class wins. This lets it emit minimal +escape sequences, folding a needed reset into the same sequence as the next +color instead of emitting a separate one. +""" + +from __future__ import annotations + +import re +import unicodedata +from typing import Any + +ESC = "\x1b[" + +# Matches a full ANSI escape sequence (color codes, cursor movement, ...). +ANSI_RE = re.compile(r"\x1b\[[0-9;:]*[A-Za-z]") + + +def strip_ansi(text: str) -> str: + """Remove ANSI escape sequences from *text*.""" + return ANSI_RE.sub("", text) + + +def displaywidth(text: str) -> int: + """Return the terminal column width of *text*, ignoring ANSI sequences. + + Wide characters (CJK, most emoji) count as two columns; combining and + zero-width characters count as zero. + """ + return sum( + 2 + if unicodedata.east_asian_width(c) in "WF" + else 0 + if unicodedata.category(c) in ("Mn", "Me", "Cf") + else 1 + for c in strip_ansi(text) + ) + + +def pad(text: str, width: int, align: str = "left") -> str: + """Pad *text* to *width* columns by display width. + + *align* is ``"left"`` (padding after), ``"right"`` (padding before), or + ``"center"``. Text already at or above *width* is returned unchanged. + """ + missing = width - displaywidth(text) + if missing <= 0: + return text + if align == "right": + return " " * missing + text + if align == "center": + left = missing // 2 + return " " * left + text + " " * (missing - left) + return text + " " * missing + + +class Colors: + """Kanta's log color palette: bare SGR parameter strings. + + Attributes are looked up when a line is rendered, so assignments such as + ``colors.action = "36"`` or additions like ``colors.session = "38;5;226"`` + take effect immediately, no matter how the object was imported. Added + colors become available on :class:`Line` under the same name. + """ + + action = "1;34" # Bold blue for the action name + user = "34" # Blue for the user display + target = "38;5;250" # White for the extra/target display + sep = "38;5;242" # Dark grey for separators + path_prefix = "38;5;242" # Dark grey for the leading part of a dotted path + path_final = "38;5;250" # White for the final path element + add = "32" # Green for additions + delete = "1;31" # Bold red for deletions + + +colors = Colors() + +# SGR attribute classes that carry no class siblings (each clears/sets itself). +_ATTR_CLASSES = frozenset({"1", "2", "3", "4", "7", "9"}) + + +def _parse_sgr(spec: str) -> dict[str, str]: + """Parse a bare SGR parameter string into a ``{class: group}`` state. + + Applies the stacking rules: ``0`` clears everything, other parameters + apply sequentially and the last one of each class wins. + """ + state: dict[str, str] = {} + tokens = spec.split(";") + i = 0 + while i < len(tokens): + token = tokens[i] + if token == "0": + state.clear() + elif token in ("38", "48"): + cls = "fg" if token == "38" else "bg" + if i + 1 < len(tokens) and tokens[i + 1] == "5": + state[cls] = ";".join(tokens[i : i + 3]) + i += 3 + continue + if i + 1 < len(tokens) and tokens[i + 1] == "2": + state[cls] = ";".join(tokens[i : i + 4]) + i += 4 + continue + state[cls] = token + elif token.isdigit() and (30 <= int(token) <= 37 or 90 <= int(token) <= 97): + state["fg"] = token + elif token.isdigit() and (40 <= int(token) <= 47 or 100 <= int(token) <= 107): + state["bg"] = token + elif token in _ATTR_CLASSES: + state[token] = token + else: + state[f"other:{token}"] = token + i += 1 + return state + + +def _sgr_transition(current: dict[str, str], new: dict[str, str]) -> str: + """Return the minimal escape sequence moving from *current* to *new*.""" + if current == new: + return "" + if not new: + return f"{ESC}0m" if current else "" + if not current: + return f"{ESC}{';'.join(new.values())}m" + if current.keys() - new.keys(): + # Some attribute must be cleared; fold the reset into one sequence. + return f"{ESC}0;{';'.join(new.values())}m" + changed = [group for cls, group in new.items() if current.get(cls) != group] + return f"{ESC}{';'.join(changed)}m" if changed else "" + + +class Line: + """Build a terminal string part by part with colors, width and alignment. + + Calling the builder appends content (arguments are converted to ``str``). + Attribute access with a color name arms that palette color for the next + call; the color is reset automatically when that call ends, so a color + always applies to exactly one call:: + + str(Line().user("Alice")(" by ")) # "Alice" blue, " by " plain + + ``width`` and ``align`` keyword arguments pad the content of a call by + display width. ``str(line)`` finishes the line, restoring default + colors if any are active. + """ + + def __init__(self, palette: Colors | None = None) -> None: + self._palette = palette if palette is not None else colors + self._parts: list[str] = [] + self._active: dict[str, str] = {} + self._pending: dict[str, str] = {} + + def __getattr__(self, name: str) -> Line: + if name.startswith("_"): + raise AttributeError(name) + spec = getattr(self._palette, name, None) + if spec is None: + raise AttributeError(f"unknown color: {name!r}") + self._pending = _parse_sgr(spec) + return self + + def __call__(self, *args: Any, width: int = 0, align: str = "left") -> Line: + text = "".join(str(arg) for arg in args) + if width: + text = pad(text, width, align) + if self._pending != self._active: + self._parts.append(_sgr_transition(self._active, self._pending)) + self._active = self._pending + self._parts.append(text) + self._pending = {} + return self + + def __str__(self) -> str: + if self._active: + return "".join(self._parts) + f"{ESC}0m" + return "".join(self._parts) diff --git a/tests/test_format_diff.py b/tests/test_format_diff.py index ddb8fe4..6127f13 100644 --- a/tests/test_format_diff.py +++ b/tests/test_format_diff.py @@ -1,4 +1,8 @@ -from kanta.logging import _ADD, _DELETE, format_diff +from kanta.logging import format_diff +from kanta.tty import ESC, colors + +_ADD = f"{ESC}{colors.add}m" +_DELETE = f"{ESC}{colors.delete}m" def test_add(): diff --git a/tests/test_logemit.py b/tests/test_logemit.py new file mode 100644 index 0000000..e32512e --- /dev/null +++ b/tests/test_logemit.py @@ -0,0 +1,157 @@ +import logging + +import pytest + +from kanta.logging import ( + LogEvent, + bootstrap_logger, + configure_logging, + emit_event, + migration_logger, + transaction_logger, +) +from tests.support import Data, make_kanta + + +@pytest.fixture(autouse=True) +def _reset_kanta_loggers(): + yield + for name in ( + "kanta", + "kanta.transaction", + "kanta.transaction.diff", + "kanta.bootstrap", + "kanta.migration", + ): + logger = logging.getLogger(name) + logger.setLevel(logging.NOTSET) + logger.propagate = True + logger.disabled = False + logger.handlers.clear() + + +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() + calls = [] + + def first(ev): + calls.append("first") + return None + + def second(ev): + calls.append("second") + + emit_event(_change_event(), [first, second]) + assert calls == ["first"] + assert capsys.readouterr().err == "" + + +def test_emit_event_truthy_return_falls_back_to_default(capsys): + logging.getLogger("kanta").handlers.clear() + configure_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() + calls = [] + + def first(ev): + calls.append("first") + ev.extra = "tgt" + return True + + def second(ev): + calls.append(("second", ev.extra)) + return True + + emit_event(_change_event(), [first, second]) + assert calls == ["first", ("second", "tgt")] + assert "tgt" in capsys.readouterr().err + + +def test_emit_event_handler_error_falls_back_to_default(capsys): + logging.getLogger("kanta").handlers.clear() + configure_logging() + + def boom(ev): + raise RuntimeError("broken") + + emit_event(_change_event(), [boom]) + assert "update" in capsys.readouterr().err + + +def test_diff_lines_built_lazily(monkeypatch): + def _boom(*args, **kwargs): + raise AssertionError("format_diff should not be called") + + monkeypatch.setattr("kanta.logging.format_diff", _boom) + ev = _change_event(diff={"counter": 1}) + emit_event(ev, [lambda ev: None]) # handled without touching the diff + monkeypatch.undo() + assert len(ev.diff_lines) == 1 + assert "counter" in ev.diff_lines[0] + + +def test_default_emit_created_and_migrated(capsys): + logging.getLogger("kanta").handlers.clear() + configure_logging() + emit_event(LogEvent(kind="created", logger=bootstrap_logger, filename="x.kantadb")) + emit_event( + LogEvent( + kind="migrated", + logger=migration_logger, + filename="x.kantadb", + from_version=0, + to_version=1, + migrations=["migrate_v1 (rename)"], + ) + ) + err = capsys.readouterr().err + assert "Created x.kantadb" in err + assert "Migrated x.kantadb v0 -> v1: migrate_v1 (rename)" in err + + +@pytest.mark.asyncio +async def test_logemit_receives_transaction_events(tmp_path, format_config): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + events = [] + kanta.logemit(lambda ev: events.append(ev) or True) + await kanta.open() + + with kanta.transaction(action="inc", user="u1", extra="x") as data: + data.counter = 1 + + await kanta.close() + + change = events[-1] + assert change.kind == "change" + assert change.action == "inc" + assert change.user == "u1" + assert change.extra == "x" + assert change.diff == {"counter": 1} + assert change.logger.name == "kanta.transaction" + + +def test_logemit_rejects_classes_and_async(tmp_path, format_config): + kanta = make_kanta(tmp_path / "test.db", Data, format_config) + + class NotAFunction: + pass + + with pytest.raises(TypeError): + kanta.logemit(NotAFunction) + + async def ahandler(ev): + return None + + with pytest.raises(TypeError): + kanta.logemit(ahandler) diff --git a/tests/test_logging.py b/tests/test_logging.py index 901ecdc..52960c5 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -3,28 +3,22 @@ import logging import pytest from kanta.logging import ( - _ACTION, - _RESET, - _TARGET, - _USER, - colorize_header_parts, configure_logging, + format_action_header, log_change, ) +from kanta.tty import ESC -def test_colorize_header_parts(): - action, user, extra = colorize_header_parts("update", "alice", "tgt") - assert action == f"{_ACTION}update{_RESET}" - assert user == f"{_USER}alice{_RESET}" - assert extra == f"{_TARGET}tgt{_RESET}" +def test_format_action_header(): + header = format_action_header("update", "alice", "tgt") + assert header == ( + f"{ESC}1;34mupdate{ESC}0m {ESC}38;5;250mtgt{ESC}0m by {ESC}34malice{ESC}0m" + ) -def test_colorize_header_parts_missing_user_and_extra(): - action, user, extra = colorize_header_parts("update") - assert action == f"{_ACTION}update{_RESET}" - assert user == "" - assert extra == "" +def test_format_action_header_action_only(): + assert format_action_header("update") == f"{ESC}1;34mupdate{ESC}0m" @pytest.fixture(autouse=True) @@ -84,7 +78,7 @@ def test_log_change_appends_extra_string(capsys): log_change("export", {}, extra="mydb.db") captured = capsys.readouterr() assert "export" in captured.err - assert f"{_TARGET}mydb.db{_RESET}" in captured.err + assert f"{ESC}38;5;250mmydb.db{ESC}0m" in captured.err def test_log_change_log_diff_false(capsys, monkeypatch): diff --git a/tests/test_tty.py b/tests/test_tty.py new file mode 100644 index 0000000..d070f71 --- /dev/null +++ b/tests/test_tty.py @@ -0,0 +1,74 @@ +import pytest + +from kanta.tty import ESC, Colors, Line, colors, displaywidth, pad, strip_ansi + + +def test_strip_ansi(): + assert strip_ansi(f"{ESC}1;34mhello{ESC}0m") == "hello" + + +def test_displaywidth_plain_and_ansi(): + assert displaywidth("hello") == 5 + assert displaywidth(f"{ESC}38;5;226mhi{ESC}0m") == 2 + + +def test_displaywidth_wide_and_combining_chars(): + assert displaywidth("你儽") == 4 + assert displaywidth("šŸš€") == 2 + assert displaywidth("eĢ") == 1 + + +def test_pad(): + assert pad("ab", 4) == "ab " + assert pad("ab", 4, align="right") == " ab" + assert pad("ab", 5, align="center") == " ab " + assert pad("abcdef", 4) == "abcdef" + assert pad("你儽", 6) == "你儽 " + + +def test_line_plain_and_str_conversion(): + assert str(Line()("n=", 42)) == "n=42" + + +def test_line_color_auto_resets_on_next_call(): + assert str(Line().user("Alice")(" by ")) == f"{ESC}34mAlice{ESC}0m by " + + +def test_line_str_restores_active_color(): + assert str(Line().user("Alice")) == f"{ESC}34mAlice{ESC}0m" + + +def test_line_same_color_not_reemitted(): + assert str(Line().user("a").user("b")) == f"{ESC}34mab{ESC}0m" + + +def test_line_transition_folds_reset_into_one_sequence(): + # bold blue -> plain blue: the bold clear rides in the same sequence + assert str(Line().action("a").user("b")) == f"{ESC}1;34ma{ESC}0;34mb{ESC}0m" + + +def test_line_unknown_color_raises(): + with pytest.raises(AttributeError, match="unknown color"): + Line().nosuchcolor("x") + + +def test_line_palette_addition(monkeypatch): + monkeypatch.setattr(colors, "session", "38;5;226", raising=False) + assert str(Line().session("3")) == f"{ESC}38;5;226m3{ESC}0m" + + +def test_line_palette_override_takes_effect(monkeypatch): + monkeypatch.setattr(colors, "user", "36") + assert str(Line().user("x")) == f"{ESC}36mx{ESC}0m" + + +def test_line_custom_palette(): + palette = Colors() + palette.brand = "35" + assert str(Line(palette).brand("x")) == f"{ESC}35mx{ESC}0m" + + +def test_line_width_and_align(): + assert str(Line()("ab", width=4)) == "ab " + assert str(Line()("ab", width=4, align="right")) == " ab" + assert str(Line().user("ab", width=4)) == f"{ESC}34mab {ESC}0m" -- 2.55.0 From 54d01f1e74a6f7504f24135c2c388e48ac07dfdd Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:23:33 +0000 Subject: [PATCH 15/24] Fortify logging: no logging failure may break functionality emit_event now swallows and reports any failure, including crashes in the built-in default_emit formatting itself; log_change routes through it. logfmt chain callbacks that raise are logged and treated as fall-through, and logmigr callbacks get on_error reporting like fatal_error handlers, so a broken logging callback can no longer abort a transaction or open. Demo: raw user ids in v0 logs, logfmt-resolved names in v1 logs. --- demo/main.py | 19 ++++++---- docs/database.md | 5 +++ kanta/callbacks.py | 11 +++++- kanta/kantaimpl.py | 6 +++ kanta/logging.py | 33 ++++++++++------- tests/test_logemit.py | 86 ++++++++++++++++++++++++++++++++++++++++++- 6 files changed, 137 insertions(+), 23 deletions(-) diff --git a/demo/main.py b/demo/main.py index 6a7282b..ec87ddc 100644 --- a/demo/main.py +++ b/demo/main.py @@ -46,7 +46,6 @@ def migrate_v1(d: dict) -> None: kanta_v1 = Kanta(filename, Data(), migrations=sys.modules[__name__]) -@kanta_v0.logfmt @kanta_v1.logfmt def resolve_user( value: str, path: str, previous: DictPre, current: DictPost @@ -75,9 +74,6 @@ async def main() -> None: data.users["userid002"]["role"] = "editor" data.counter = 1 - with kanta.transaction(action="delete", user="userid002") as data: - del data.users["userid001"] - # Display-only extra string, appended after the action. with kanta.transaction( action="export", user="userid002", extra="extra info" @@ -91,11 +87,18 @@ async def main() -> None: except ValueError: print(f"# Reading does not need transaction: {data.counter=}", flush=True) - with kanta.transaction(action="import", logdiff=False) as data: - data.counter = 3 - - print("\n# A later version of our application with new data model and migrations") + print( + "\n# A later version of our application with new data model, migrations and logfmt" + ) async with kanta_v1 as kanta: + with kanta.transaction( + action="import", user="userid001", logdiff=False + ) as data: + data.total = 3 + + with kanta.transaction(action="delete", user="userid002") as data: + del data.users["userid001"] + with kanta.transaction( action="update", user="userid002", extra=filename.name ) as data: diff --git a/docs/database.md b/docs/database.md index 2b6be26..6234f74 100644 --- a/docs/database.md +++ b/docs/database.md @@ -244,6 +244,11 @@ def resolve_user_key(value: str) -> str | None: also call `default_emit(event)` itself to delegate events it does not customize. Operational diagnostics (rollback warnings, integrity errors) do not go through this mechanism. +- Logging never breaks functionality: a crashing `logemit` callback is + reported with `logger.exception` and the event falls back to the built-in + formatting; if the built-in formatting itself fails, the error is reported + and swallowed. The same applies to `logfmt` callbacks (a failing one is + treated as a fall-through) and `logmigr` callbacks. ```python @kanta.logemit diff --git a/kanta/callbacks.py b/kanta/callbacks.py index 126b467..5cf6dd1 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -12,6 +12,7 @@ and receive the value plus an optional ``path`` string. They return from __future__ import annotations import inspect +import logging import types from collections.abc import Callable from dataclasses import dataclass @@ -23,6 +24,8 @@ from kanta.migrations import MigrationResult DictPre = Annotated[dict, "pre"] DictPost = Annotated[dict, "post"] +_logger = logging.getLogger(__name__) + class LogFmt: """Base class for stateful logfmt callbacks. @@ -226,7 +229,13 @@ class CallbackRegistry: for fn, pattern in formatters: if pattern is not None and path != pattern: continue - resolved = fn(value, path) + try: + resolved = fn(value, path) + except Exception: + # Formatting must never break functionality; a failing + # callback is reported and treated as a fall-through. + _logger.exception("logfmt callback %r failed", fn) + continue if resolved is not None: return resolved return None diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index 082e38d..a598119 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -29,6 +29,11 @@ _logger = logging.getLogger(__name__) T = TypeVar("T") +def _log_callback_error(callback_error, callback): + """Report a failing logging callback and continue with the next one.""" + _logger.exception("Log callback %r failed: %s", callback, callback_error) + + class KantaImpl(PersistenceMixin, Generic[T]): """Internal state and logic for Kanta.""" @@ -106,6 +111,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): kanta=self._kanta, migration_result=migration_result, ), + on_error=_log_callback_error, ) return diff --git a/kanta/logging.py b/kanta/logging.py index 5f29db2..cc9d705 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -94,16 +94,23 @@ def emit_event( A truthy return value passes the event ā€” possibly modified ā€” to the next handler. When all handlers pass, :func:`default_emit` renders the event with the built-in formatting. + + Logging must never break functionality: a crashing handler is reported + and the chain falls back to the built-in formatting, and a failure in + the built-in formatting itself is reported and swallowed. """ - for handler in handlers: - try: - proceed = handler(ev) - except Exception: - _logger.exception("logemit callback failed, using default formatting") - break - if not proceed: - return - default_emit(ev) + try: + for handler in handlers: + try: + proceed = handler(ev) + except Exception: + _logger.exception("logemit callback failed, using default formatting") + break + if not proceed: + return + default_emit(ev) + except Exception: + _logger.exception("failed to emit %s log event", ev.kind) def default_emit(ev: LogEvent) -> None: @@ -406,9 +413,9 @@ def log_change( ) -> None: """Log a database change with the built-in formatting. - Compatibility wrapper around :func:`default_emit`; Kanta itself builds a - :class:`LogEvent` and dispatches it through :func:`emit_event` so logemit - callbacks see it. + Compatibility wrapper around :func:`emit_event` with no handlers; Kanta + itself builds a :class:`LogEvent` and dispatches it with the registered + logemit callbacks. Args: action: The action name (e.g., "login", "admin:delete_user"). @@ -423,7 +430,7 @@ def log_change( log_diff: Whether to build and emit the diff lines. ``False`` skips diff formatting entirely and only the header is logged. """ - default_emit( + emit_event( LogEvent( kind="change", logger=logger, diff --git a/tests/test_logemit.py b/tests/test_logemit.py index e32512e..38c3131 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -1,4 +1,5 @@ import logging +import sys import pytest @@ -7,10 +8,17 @@ from kanta.logging import ( bootstrap_logger, configure_logging, emit_event, + log_change, migration_logger, transaction_logger, ) -from tests.support import Data, make_kanta +from kanta.migrations import MigrationResult +from tests.support import ( + Data, + fixed_change, + make_kanta, + seed_single_change, +) @pytest.fixture(autouse=True) @@ -155,3 +163,79 @@ def test_logemit_rejects_classes_and_async(tmp_path, format_config): with pytest.raises(TypeError): kanta.logemit(ahandler) + + +def _raise(*args, **kwargs): + raise RuntimeError("formatting broken") + + +def test_log_change_never_raises(monkeypatch): + monkeypatch.setattr("kanta.logging.format_action_header", _raise) + log_change("update", {"counter": 1}, previous={}) # must not raise + + +@pytest.mark.asyncio +async def test_logging_failure_does_not_break_transaction( + tmp_path, format_config, monkeypatch +): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + kanta.logemit(_raise) + monkeypatch.setattr("kanta.logging.format_action_header", _raise) + await kanta.open() + + with kanta.transaction(action="inc") as data: + data.counter = 1 + + await kanta.close() + + kanta2 = make_kanta(path, Data, format_config) + kanta2.logemit(_raise) + monkeypatch.setattr("kanta.logging.format_action_header", _raise) + await kanta2.open() + assert kanta2.data.counter == 1 + await kanta2.close() + + +@pytest.mark.asyncio +async def test_logfmt_failure_falls_back_to_default(tmp_path, format_config, caplog): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + + @kanta.logfmt + def bad(value: str, path: str) -> str | None: + raise RuntimeError("broken") + + await kanta.open() + with caplog.at_level(logging.INFO, logger="kanta.transaction"): + with kanta.transaction(action="inc", user="alice") as data: + data.counter = 1 + await kanta.close() + + assert kanta.data.counter == 1 + assert "alice" in caplog.text # raw rendering used despite the failure + assert "counter" in caplog.text + + +@pytest.mark.asyncio +async def test_logmigr_failure_does_not_break_open(tmp_path, format_config): + path = tmp_path / "test.db" + seed_single_change(path, fixed_change("init", {"counter": 0}), format_config) + + mod = type(sys)("test_migrations_broken_logmigr") + + def migrate_v1(d, kanta): + """Bump counter.""" + d["counter"] = 2 + + mod.__dict__["migrate_v1"] = migrate_v1 + + kanta = make_kanta(path, Data, format_config, migrations=mod) + + @kanta.logmigr + def bad(summary: MigrationResult) -> None: + raise RuntimeError("broken") + + await kanta.open() + assert kanta.data.counter == 2 + await kanta.close() -- 2.55.0 From f131f727494113b573e6faf2ff496df0ffdc94de Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:31:48 +0000 Subject: [PATCH 16/24] Demo: simplify resolve_user to a plain previous-state lookup --- demo/main.py | 22 +++++----------------- 1 file changed, 5 insertions(+), 17 deletions(-) diff --git a/demo/main.py b/demo/main.py index ec87ddc..09ec190 100644 --- a/demo/main.py +++ b/demo/main.py @@ -7,7 +7,7 @@ from pathlib import Path import msgspec from kanta import Kanta -from kanta.callbacks import DictPost, DictPre +from kanta.callbacks import DictPre from kanta.logging import configure_logging @@ -47,18 +47,11 @@ kanta_v1 = Kanta(filename, Data(), migrations=sys.modules[__name__]) @kanta_v1.logfmt -def resolve_user( - value: str, path: str, previous: DictPre, current: DictPost -) -> str | None: +def resolve_user(value: str, path: str, previous: DictPre) -> str | None: """Resolve user ids to names from the database state itself.""" if path != "$user" and not path.startswith("users."): return None - # Post-change state first, then pre-change (deleted users are only there). - for state in (current, previous): - name = state.get("users", {}).get(value, {}).get("name") - if name: - return name - return None + return previous.get("users", {}).get(value, {}).get("name") async def main() -> None: @@ -92,18 +85,13 @@ async def main() -> None: ) async with kanta_v1 as kanta: with kanta.transaction( - action="import", user="userid001", logdiff=False + action="update", user="userid002", extra=filename.name ) as data: - data.total = 3 + data.total += 1 with kanta.transaction(action="delete", user="userid002") as data: del data.users["userid001"] - with kanta.transaction( - action="update", user="userid002", extra=filename.name - ) as data: - data.total = 4 - # Fake clock for deterministic timestamps _now = datetime(2027, 1, 1, tzinfo=UTC) -- 2.55.0 From 79faa220df578616c52a742189ffd166d2c1ec99 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:40:01 +0000 Subject: [PATCH 17/24] Route transaction aborts through logemit as 'aborted' events The rollback warning is now a LogEvent (kind='aborted', WARNING level, carrying the exception) dispatched via emit_event so logemit callbacks can handle or restyle it. Default rendering: action in transaction color without quotes, followed by ' transaction aborted: {exc}' in default color. --- docs/database.md | 23 ++++++++++++----------- kanta/logging.py | 15 ++++++++++++--- kanta/transaction.py | 13 +++++++++++-- tests/test_logemit.py | 27 +++++++++++++++++++++++++++ 4 files changed, 62 insertions(+), 16 deletions(-) diff --git a/docs/database.md b/docs/database.md index 6234f74..5464ab0 100644 --- a/docs/database.md +++ b/docs/database.md @@ -225,16 +225,17 @@ def resolve_user_key(value: str) -> str | None: #### Log Emitters - Every change-related message Kanta emits (transaction/bootstrap/migration - changes, `Created `, migration summaries) is described by a - `kanta.logging.LogEvent` and dispatched through `kanta.logging.emit_event`. - Kanta's own output goes through the same mechanism: when no `logemit` - callback handles an event, `kanta.logging.default_emit` renders it with the - built-in formatting. + changes, `Created `, migration summaries, aborted transactions) is + described by a `kanta.logging.LogEvent` and dispatched through + `kanta.logging.emit_event`. Kanta's own output goes through the same + mechanism: when no `logemit` callback handles an event, + `kanta.logging.default_emit` renders it with the built-in formatting. - A `LogEvent` carries the event `kind` (`"change"`, `"created"`, - `"migrated"`), the preferred `logger` and `level`, and all relevant state: - `action`, `user`, `extra`, `diff`, `previous`/`current` state dicts, the - built `logfmt` chain, and version info for migration events. Pretty - `header` and `diff_lines` are lazy properties, built only if accessed. + `"migrated"`, `"aborted"`), the preferred `logger` and `level`, and all + relevant state: `action`, `user`, `extra`, `error` (for aborted + transactions), `diff`, `previous`/`current` state dicts, the built `logfmt` + chain, and version info for migration events. Pretty `header` and + `diff_lines` are lazy properties, built only if accessed. - `@kanta.logemit` registers a callback receiving the event. The callback decides what is logged and where: it may log one or more messages on `event.logger`, log somewhere else, or nothing at all. A falsy return @@ -242,8 +243,8 @@ def resolve_user_key(value: str) -> str | None: passes the event ā€” possibly modified ā€” to the next registered callback. When all callbacks pass, `default_emit` renders the event; a callback may also call `default_emit(event)` itself to delegate events it does not - customize. Operational diagnostics (rollback warnings, integrity errors) - do not go through this mechanism. + customize. Operational diagnostics (integrity errors, background flush + failures) do not go through this mechanism. - Logging never breaks functionality: a crashing `logemit` callback is reported with `logger.exception` and the event falls back to the built-in formatting; if the built-in formatting itself fails, the error is reported diff --git a/kanta/logging.py b/kanta/logging.py index cc9d705..80e0bf2 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -40,9 +40,10 @@ class LogEvent(msgspec.Struct, kw_only=True): """All state describing one loggable event, passed to logemit callbacks. ``kind`` is ``"change"`` (transaction, bootstrap, or migration diff), - ``"created"`` (database file created), or ``"migrated"`` (migration - summary). ``logger`` and ``level`` are Kanta's preferred destination; - a callback may use them, log elsewhere, or not log at all. + ``"created"`` (database file created), ``"migrated"`` (migration + summary), or ``"aborted"`` (transaction rolled back). ``logger`` and + ``level`` are Kanta's preferred destination; a callback may use them, + log elsewhere, or not log at all. The event is mutable: a callback may modify it before returning a truthy value to pass it on, affecting later callbacks and the built-in fallback. @@ -54,6 +55,7 @@ class LogEvent(msgspec.Struct, kw_only=True): action: str | None = None user: str | None = None extra: str | None = None + error: BaseException | None = None diff: dict = msgspec.field(default_factory=dict) previous: dict | None = None current: dict | None = None @@ -134,6 +136,13 @@ def default_emit(ev: LogEvent) -> None: ) return + if ev.kind == "aborted": + message = str( + Line().action(ev.action or "")(f" transaction aborted: {ev.error}") + ) + ev.logger.log(ev.level, message) + return + # kind == "change": diff lines go to the .diff child logger so # they can be silenced or routed separately from the headers. diff_logger = logging.getLogger(f"{ev.logger.name}.diff") diff --git a/kanta/transaction.py b/kanta/transaction.py index 3be160a..3c9bbfd 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -102,8 +102,17 @@ def transaction( ), impl.callback_registry.logemit_handlers, ) - except Exception: - _logger.warning("Transaction '%s' failed, rolling back changes", action) + except Exception as exc: + emit_event( + LogEvent( + kind="aborted", + logger=transaction_logger, + level=logging.WARNING, + action=action, + error=exc, + ), + impl.callback_registry.logemit_handlers, + ) if impl.transaction_snapshot is not None: impl.data = restore_data_in_place( impl.data, diff --git a/tests/test_logemit.py b/tests/test_logemit.py index 38c3131..5949242 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -239,3 +239,30 @@ async def test_logmigr_failure_does_not_break_open(tmp_path, format_config): await kanta.open() assert kanta.data.counter == 2 await kanta.close() + + +@pytest.mark.asyncio +async def test_aborted_transaction_emits_event(tmp_path, format_config, caplog): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + events = [] + kanta.logemit(lambda ev: events.append(ev) or True) + await kanta.open() + + with caplog.at_level(logging.WARNING, logger="kanta.transaction"): + with pytest.raises(ValueError): + with kanta.transaction(action="reset") as data: + data.counter = 99 + raise ValueError("simulated failure") + + await kanta.close() + + aborted = events[-1] + assert aborted.kind == "aborted" + assert aborted.action == "reset" + assert aborted.level == logging.WARNING + assert isinstance(aborted.error, ValueError) + messages = [r.getMessage() for r in caplog.records if r.levelno == logging.WARNING] + assert any("\x1b[1;34mreset" in m for m in messages) # action color, no quotes + assert any(" transaction aborted: simulated failure" in m for m in messages) + assert kanta.data.counter == 0 # rolled back -- 2.55.0 From cc319ce0656e3407155058659025feb81c7e880b Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:45:31 +0000 Subject: [PATCH 18/24] Include 'by user' in abort messages The aborted event now carries the transaction user, resolved through the logfmt chain against the pre-transaction state so it matches change headers. Default rendering: ' by transaction aborted: '. User resolution factored into _build_logfmt/_resolve_user helpers shared by the change and abort paths. --- demo/main.py | 2 +- docs/database.md | 6 ++++-- kanta/logging.py | 9 +++++---- kanta/transaction.py | 39 ++++++++++++++++++++++++++------------- tests/test_logemit.py | 24 ++++++++++++++++++++++++ 5 files changed, 60 insertions(+), 20 deletions(-) diff --git a/demo/main.py b/demo/main.py index 09ec190..3f88215 100644 --- a/demo/main.py +++ b/demo/main.py @@ -74,7 +74,7 @@ async def main() -> None: data.counter = 2 try: - with kanta.transaction(action="reset") as data: + with kanta.transaction(action="reset", user="foo") as data: data.counter = 99 raise ValueError("simulated failure") except ValueError: diff --git a/docs/database.md b/docs/database.md index 5464ab0..84eac47 100644 --- a/docs/database.md +++ b/docs/database.md @@ -234,8 +234,10 @@ def resolve_user_key(value: str) -> str | None: `"migrated"`, `"aborted"`), the preferred `logger` and `level`, and all relevant state: `action`, `user`, `extra`, `error` (for aborted transactions), `diff`, `previous`/`current` state dicts, the built `logfmt` - chain, and version info for migration events. Pretty `header` and - `diff_lines` are lazy properties, built only if accessed. + chain, and version info for migration events. The default `"aborted"` + rendering is `[ by ] transaction aborted: ` with the + action and user colored and the user resolved via `logfmt`. Pretty + `header` and `diff_lines` are lazy properties, built only if accessed. - `@kanta.logemit` registers a callback receiving the event. The callback decides what is logged and where: it may log one or more messages on `event.logger`, log somewhere else, or nothing at all. A falsy return diff --git a/kanta/logging.py b/kanta/logging.py index 80e0bf2..592bf4d 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -137,10 +137,11 @@ def default_emit(ev: LogEvent) -> None: return if ev.kind == "aborted": - message = str( - Line().action(ev.action or "")(f" transaction aborted: {ev.error}") - ) - ev.logger.log(ev.level, message) + line = Line().action(ev.action or "") + if ev.user: + line(" by ").user(ev.user) + line(f" transaction aborted: {ev.error}") + ev.logger.log(ev.level, str(line)) return # kind == "change": diff lines go to the .diff child logger so diff --git a/kanta/transaction.py b/kanta/transaction.py index 3c9bbfd..5dd8509 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -15,6 +15,25 @@ from kanta.serialization import restore_data_in_place, struct_to_dict _logger = logging.getLogger(__name__) +def _build_logfmt(impl, previous: dict, current: dict): + """Build the logfmt chain for a state transition.""" + return impl.callback_registry.build_logfmt( + InjectionContext( + previous_state=previous, + current_state=current, + kanta=impl._kanta, + ) + ) + + +def _resolve_user(logfmt, user: str | None) -> str | None: + """Resolve *user* for display via the logfmt chain (raw as fallback).""" + if user is None: + return None + resolved = logfmt(user, _USER_PATH) + return resolved if resolved is not None else user + + @contextmanager def transaction( impl, @@ -71,18 +90,7 @@ def transaction( previous = impl.statedict record = impl.queue_change(action, new_dict, user=user, mtime=mtime) if record is not None: - logfmt = impl.callback_registry.build_logfmt( - InjectionContext( - previous_state=previous, - current_state=new_dict, - kanta=impl._kanta, - ) - ) - formatted_user = user - if user is not None and logfmt is not None: - resolved = logfmt(user, _USER_PATH) - if resolved is not None: - formatted_user = resolved + logfmt = _build_logfmt(impl, previous, new_dict) if log is not False: logger = ( log if isinstance(log, logging.Logger) else transaction_logger @@ -92,7 +100,7 @@ def transaction( kind="change", logger=logger, action=action, - user=formatted_user, + user=_resolve_user(logfmt, user), extra=extra, diff=record.diff, previous=previous, @@ -103,12 +111,17 @@ def transaction( impl.callback_registry.logemit_handlers, ) except Exception as exc: + resolved_user = None + if user is not None: + logfmt = _build_logfmt(impl, impl.statedict, impl.statedict) + resolved_user = _resolve_user(logfmt, user) emit_event( LogEvent( kind="aborted", logger=transaction_logger, level=logging.WARNING, action=action, + user=resolved_user, error=exc, ), impl.callback_registry.logemit_handlers, diff --git a/tests/test_logemit.py b/tests/test_logemit.py index 5949242..6e21f6f 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -266,3 +266,27 @@ async def test_aborted_transaction_emits_event(tmp_path, format_config, caplog): assert any("\x1b[1;34mreset" in m for m in messages) # action color, no quotes assert any(" transaction aborted: simulated failure" in m for m in messages) assert kanta.data.counter == 0 # rolled back + + +@pytest.mark.asyncio +async def test_aborted_transaction_includes_resolved_user( + tmp_path, format_config, caplog +): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + + @kanta.logfmt + def resolve(value: str, path: str) -> str | None: + return "Alice" if value == "u1" else None + + await kanta.open() + with caplog.at_level(logging.WARNING, logger="kanta.transaction"): + with pytest.raises(ValueError): + with kanta.transaction(action="reset", user="u1") as data: + data.counter = 99 + raise ValueError("boom") + await kanta.close() + + messages = [r.getMessage() for r in caplog.records if r.levelno == logging.WARNING] + assert any(" by " in m and "Alice" in m for m in messages) + assert any(" transaction aborted: boom" in m for m in messages) -- 2.55.0 From c90db530fd4c918e2383dc5e6ecfcf5fe8c332c4 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:52:26 +0000 Subject: [PATCH 19/24] Unify default emitter around universal LogEvent.header All event kinds now share one shape: a one-line header plus an optional diff body for changes. LogEvent.header is a lazy property covering every kind (change, aborted, created, migrated), and default_emit reduces to logging the header plus routing diff_lines to the .diff child logger. Custom emitters can tap the same blocks - header, diff_lines, Line, format_diff - instead of reimplementing formatting per message type. --- demo/main.py | 14 +++++------ docs/database.md | 14 +++++++---- kanta/logging.py | 56 ++++++++++++++++++++++--------------------- tests/test_logemit.py | 25 +++++++++++++++++++ 4 files changed, 71 insertions(+), 38 deletions(-) diff --git a/demo/main.py b/demo/main.py index 3f88215..1bdb436 100644 --- a/demo/main.py +++ b/demo/main.py @@ -73,13 +73,6 @@ async def main() -> None: ) as data: data.counter = 2 - try: - with kanta.transaction(action="reset", user="foo") as data: - data.counter = 99 - raise ValueError("simulated failure") - except ValueError: - print(f"# Reading does not need transaction: {data.counter=}", flush=True) - print( "\n# A later version of our application with new data model, migrations and logfmt" ) @@ -89,6 +82,13 @@ async def main() -> None: ) as data: data.total += 1 + try: + with kanta.transaction(action="reset", user="userid001") as data: + data.total = 99 + raise ValueError("simulated failure") + except ValueError: + print(f"# Reading does not need transaction: {data.total=}", flush=True) + with kanta.transaction(action="delete", user="userid002") as data: del data.users["userid001"] diff --git a/docs/database.md b/docs/database.md index 84eac47..35fe7b3 100644 --- a/docs/database.md +++ b/docs/database.md @@ -234,10 +234,16 @@ def resolve_user_key(value: str) -> str | None: `"migrated"`, `"aborted"`), the preferred `logger` and `level`, and all relevant state: `action`, `user`, `extra`, `error` (for aborted transactions), `diff`, `previous`/`current` state dicts, the built `logfmt` - chain, and version info for migration events. The default `"aborted"` - rendering is `[ by ] transaction aborted: ` with the - action and user colored and the user resolved via `logfmt`. Pretty - `header` and `diff_lines` are lazy properties, built only if accessed. + chain, and version info for migration events. +- The built-in formatting is assembled from standard blocks that custom + emitters can reuse as-is or replace piecemeal: + - `event.header` ā€” a lazy property producing the default one-line header + for any kind: `[ ][ by ]` for changes, + `[ by ] transaction aborted: ` for aborts, and the + plain `Created`/`Migrated` summaries. + - `event.diff_lines` ā€” a lazy property producing the pretty diff body for + change events (built only if accessed). + - `default_emit` itself is just `header` plus the `diff_lines` routing. - `@kanta.logemit` registers a callback receiving the event. The callback decides what is logged and where: it may log one or more messages on `event.logger`, log somewhere else, or nothing at all. A falsy return diff --git a/kanta/logging.py b/kanta/logging.py index 592bf4d..293484f 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -70,13 +70,33 @@ class LogEvent(msgspec.Struct, kw_only=True): @property def header(self) -> str: - """The default header line (colored), built on first access.""" + """The default one-line header for this event, built on first access. + + Covers every event kind: ``"[ ][ by ]"`` for + changes, ``"[ by ] transaction aborted: "`` for + aborts, and the plain ``Created``/``Migrated`` summaries. + """ if self._header is None: - self._header = format_action_header( - self.action or "", self.user, self.extra - ) + self._header = self._build_header() return self._header + def _build_header(self) -> str: + if self.kind == "created": + return f"Created {self.filename}" + if self.kind == "migrated": + migrations = ", ".join(self.migrations) + return ( + f"Migrated {self.filename} " + f"v{self.from_version} -> v{self.to_version}: {migrations}" + ) + if self.kind == "change": + return format_action_header(self.action or "", self.user, self.extra) + line = Line().action(self.action or "") + if self.user: + line(" by ").user(self.user) + line(f" transaction aborted: {self.error}") + return str(line) + @property def diff_lines(self) -> list[str]: """Pretty-printed diff lines, built on first access and cached.""" @@ -118,34 +138,16 @@ def emit_event( def default_emit(ev: LogEvent) -> None: """Emit *ev* with Kanta's built-in formatting. + Logs :attr:`LogEvent.header`; for change events the + :attr:`LogEvent.diff_lines` body follows on the ``.diff`` child + logger so it can be silenced or routed separately from the headers. This is what runs when no logemit callback handles the event; custom callbacks may call it to delegate events they do not care about. """ - if ev.kind == "created": - ev.logger.log(ev.level, "Created %s", ev.filename) + if ev.kind != "change": + ev.logger.log(ev.level, ev.header) return - if ev.kind == "migrated": - ev.logger.log( - ev.level, - "Migrated %s v%s -> v%s: %s", - ev.filename, - ev.from_version, - ev.to_version, - ", ".join(ev.migrations), - ) - return - - if ev.kind == "aborted": - line = Line().action(ev.action or "") - if ev.user: - line(" by ").user(ev.user) - line(f" transaction aborted: {ev.error}") - ev.logger.log(ev.level, str(line)) - return - - # kind == "change": diff lines go to the .diff child logger so - # they can be silenced or routed separately from the headers. diff_logger = logging.getLogger(f"{ev.logger.name}.diff") lines = ev.diff_lines if ev.show_diff and diff_logger.isEnabledFor(ev.level) else [] diff --git a/tests/test_logemit.py b/tests/test_logemit.py index 6e21f6f..311f39a 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -290,3 +290,28 @@ async def test_aborted_transaction_includes_resolved_user( messages = [r.getMessage() for r in caplog.records if r.levelno == logging.WARNING] assert any(" by " in m and "Alice" in m for m in messages) assert any(" transaction aborted: boom" in m for m in messages) + + +def test_event_header_covers_all_kinds(): + created = LogEvent(kind="created", logger=transaction_logger, filename="x.db") + assert created.header == "Created x.db" + + migrated = LogEvent( + kind="migrated", + logger=transaction_logger, + filename="x.db", + from_version=0, + to_version=1, + migrations=["migrate_v1 (rename)"], + ) + assert migrated.header == "Migrated x.db v0 -> v1: migrate_v1 (rename)" + + aborted = LogEvent( + kind="aborted", + logger=transaction_logger, + action="reset", + user="alice", + error=ValueError("boom"), + ) + assert "transaction aborted: boom" in aborted.header + assert "alice" in aborted.header -- 2.55.0 From 799b2438be32e22cb65b8aeff2b1c33b9dc51441 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 05:57:43 +0000 Subject: [PATCH 20/24] Add kanta instance to LogEvent and make header settable Every emitted event now carries the originating Kanta instance so logemit callbacks can reach application state attached to it. The header property gains a setter, formalizing restyle-then-delegate: assign ev.header and return truthy to keep the default diff routing with a custom header. --- docs/database.md | 12 +++++++----- kanta/kantaimpl.py | 4 ++++ kanta/logging.py | 10 ++++++++++ kanta/transaction.py | 2 ++ tests/test_logemit.py | 29 +++++++++++++++++++++++++++++ 5 files changed, 52 insertions(+), 5 deletions(-) diff --git a/docs/database.md b/docs/database.md index 35fe7b3..60ffa39 100644 --- a/docs/database.md +++ b/docs/database.md @@ -231,16 +231,18 @@ def resolve_user_key(value: str) -> str | None: mechanism: when no `logemit` callback handles an event, `kanta.logging.default_emit` renders it with the built-in formatting. - A `LogEvent` carries the event `kind` (`"change"`, `"created"`, - `"migrated"`, `"aborted"`), the preferred `logger` and `level`, and all - relevant state: `action`, `user`, `extra`, `error` (for aborted - transactions), `diff`, `previous`/`current` state dicts, the built `logfmt` - chain, and version info for migration events. + `"migrated"`, `"aborted"`), the preferred `logger` and `level`, the + `kanta` instance, and all relevant state: `action`, `user`, `extra`, + `error` (for aborted transactions), `diff`, `previous`/`current` state + dicts, the built `logfmt` chain, and version info for migration events. - The built-in formatting is assembled from standard blocks that custom emitters can reuse as-is or replace piecemeal: - `event.header` ā€” a lazy property producing the default one-line header for any kind: `[ ][ by ]` for changes, `[ by ] transaction aborted: ` for aborts, and the - plain `Created`/`Migrated` summaries. + plain `Created`/`Migrated` summaries. It is settable: assign + `event.header = ...` and return truthy to restyle the header while + keeping the default diff routing. - `event.diff_lines` ā€” a lazy property producing the pretty diff body for change events (built only if accessed). - `default_emit` itself is just `header` plus the `diff_lines` routing. diff --git a/kanta/kantaimpl.py b/kanta/kantaimpl.py index a598119..7888ba5 100644 --- a/kanta/kantaimpl.py +++ b/kanta/kantaimpl.py @@ -131,6 +131,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): kind="change", logger=migration_log, level=logging.DEBUG, + kanta=self._kanta, action=info.name, diff=info.diff, previous=info.before, @@ -143,6 +144,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): LogEvent( kind="migrated", logger=migration_log, + kanta=self._kanta, filename=str(self.filename), from_version=previous_version, to_version=migration_result.version, @@ -324,6 +326,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): LogEvent( kind="created", logger=logger, + kanta=self._kanta, filename=str(self.filename.resolve()), ), self.callback_registry.logemit_handlers, @@ -344,6 +347,7 @@ class KantaImpl(PersistenceMixin, Generic[T]): LogEvent( kind="change", logger=logger, + kanta=self._kanta, action=self.bootstrap_action, user=formatted_user, diff=record.diff, diff --git a/kanta/logging.py b/kanta/logging.py index 293484f..18c4a08 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -52,6 +52,7 @@ class LogEvent(msgspec.Struct, kw_only=True): kind: str logger: logging.Logger level: int = logging.INFO + kanta: Any = None action: str | None = None user: str | None = None extra: str | None = None @@ -80,6 +81,15 @@ class LogEvent(msgspec.Struct, kw_only=True): self._header = self._build_header() return self._header + @header.setter + def header(self, value: str) -> None: + """Override the header, keeping the default diff routing. + + A logemit callback can restyle the header and return a truthy value: + :func:`default_emit` then logs this header instead of building one. + """ + self._header = value + def _build_header(self) -> str: if self.kind == "created": return f"Created {self.filename}" diff --git a/kanta/transaction.py b/kanta/transaction.py index 5dd8509..f947bed 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -99,6 +99,7 @@ def transaction( LogEvent( kind="change", logger=logger, + kanta=impl._kanta, action=action, user=_resolve_user(logfmt, user), extra=extra, @@ -120,6 +121,7 @@ def transaction( kind="aborted", logger=transaction_logger, level=logging.WARNING, + kanta=impl._kanta, action=action, user=resolved_user, error=exc, diff --git a/tests/test_logemit.py b/tests/test_logemit.py index 311f39a..a4218e7 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -315,3 +315,32 @@ def test_event_header_covers_all_kinds(): ) assert "transaction aborted: boom" in aborted.header assert "alice" in aborted.header + + +@pytest.mark.asyncio +async def test_event_carries_kanta_instance(tmp_path, format_config): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + events = [] + kanta.logemit(lambda ev: events.append(ev) or True) + await kanta.open() + with kanta.transaction(action="inc") as data: + data.counter = 1 + await kanta.close() + + assert events + assert all(ev.kanta is kanta for ev in events) + + +def test_header_is_settable_and_used_by_default_emit(capsys): + logging.getLogger("kanta").handlers.clear() + configure_logging() + + def restyle(ev): + ev.header = f"CUSTOM {ev.action}" + return True + + emit_event(_change_event(diff={"counter": 1}, previous={}), [restyle]) + err = capsys.readouterr().err + assert "CUSTOM update" in err + assert "counter" in err # default diff routing still applies -- 2.55.0 From ecd146f72ced0de933b77dd7ebcc06a6b8b56a47 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 06:04:35 +0000 Subject: [PATCH 21/24] Document kanta.ctx as the app-context channel for logemit kanta.ctx already existed as a user-writable namespace for migrations; since LogEvent carries the kanta instance, ev.kanta.ctx is also the way for applications to pass per-connection metadata to their logemit callbacks, including for creation/bootstrap events. No API change needed. --- docs/database.md | 3 +++ kanta/kanta.py | 5 ++++- tests/test_logemit.py | 15 +++++++++++++++ 3 files changed, 22 insertions(+), 1 deletion(-) diff --git a/docs/database.md b/docs/database.md index 60ffa39..fb99602 100644 --- a/docs/database.md +++ b/docs/database.md @@ -235,6 +235,9 @@ def resolve_user_key(value: str) -> str | None: `kanta` instance, and all relevant state: `action`, `user`, `extra`, `error` (for aborted transactions), `diff`, `previous`/`current` state dicts, the built `logfmt` chain, and version info for migration events. + Application-specific context (e.g. a connection id) can be stored in + `kanta.ctx` ā€” a user-writable namespace ā€” and read back in callbacks as + `event.kanta.ctx`, which also covers creation/bootstrap events. - The built-in formatting is assembled from standard blocks that custom emitters can reuse as-is or replace piecemeal: - `event.header` ā€” a lazy property producing the default one-line header diff --git a/kanta/kanta.py b/kanta/kanta.py index 3c42a71..9422977 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -130,7 +130,10 @@ class Kanta(Generic[T]): """User-writable context namespace. Migration functions receive the ``Kanta`` instance and can read or - mutate ``kanta.ctx`` during migrations. + mutate ``kanta.ctx`` during migrations. Applications can also store + arbitrary data here (e.g. a connection id); since + :class:`kanta.logging.LogEvent` carries the Kanta instance, logemit + callbacks can read it as ``event.kanta.ctx``. """ return self._impl.ctx diff --git a/tests/test_logemit.py b/tests/test_logemit.py index a4218e7..9bca8a5 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -344,3 +344,18 @@ def test_header_is_settable_and_used_by_default_emit(capsys): err = capsys.readouterr().err assert "CUSTOM update" in err assert "counter" in err # default diff routing still applies + + +@pytest.mark.asyncio +async def test_ctx_reachable_from_event(tmp_path, format_config): + path = tmp_path / "test.db" + kanta = make_kanta(path, Data, format_config) + kanta.ctx.connection_id = 7 + seen = [] + kanta.logemit(lambda ev: seen.append(ev.kanta.ctx.connection_id) or True) + await kanta.open() + with kanta.transaction(action="inc") as data: + data.counter = 1 + await kanta.close() + + assert seen and all(connection_id == 7 for connection_id in seen) -- 2.55.0 From 47f38f4a7144f3dd2be10c39182b8947f0874c38 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 06:17:17 +0000 Subject: [PATCH 22/24] Final cleanup: lazy logfmt build, docstring and example fixes - transaction.py only builds the logfmt chain when logging is enabled - callbacks.py module docstring documents the logemit special case - docs logemit example uses the settable header instead of a user lookup that would break when logfmt resolution is registered --- docs/database.md | 6 +++--- kanta/callbacks.py | 4 ++++ kanta/transaction.py | 2 +- 3 files changed, 8 insertions(+), 4 deletions(-) diff --git a/docs/database.md b/docs/database.md index fb99602..06c8e9f 100644 --- a/docs/database.md +++ b/docs/database.md @@ -269,9 +269,9 @@ def resolve_user_key(value: str) -> str | None: def emit(ev: LogEvent): if ev.kind != "change": return default_emit(ev) # delegate, no chaining needed - actor = ev.current.get("users", {}).get(ev.user, {}).get("name", ev.user) - line = Line().user(actor, width=20)(" ").action(ev.action) - ev.logger.log(ev.level, f"{line}\n" + "\n".join(ev.diff_lines)) + # Restyle the header; default_emit keeps routing the diff body. + ev.header = str(Line().user(ev.user or "-", width=20)(" ").action(ev.action)) + return True ``` #### Terminal Formatting Helpers diff --git a/kanta/callbacks.py b/kanta/callbacks.py index 5cf6dd1..034e997 100644 --- a/kanta/callbacks.py +++ b/kanta/callbacks.py @@ -7,6 +7,10 @@ default value. Log formatters are a special case: they are called per value being rendered and receive the value plus an optional ``path`` string. They return ``str | None``; ``None`` means "fall through to the next formatter". + +Log emitters (``logemit``) are another special case: plain callables that +receive a :class:`kanta.logging.LogEvent` and are dispatched by +:func:`kanta.logging.emit_event`. """ from __future__ import annotations diff --git a/kanta/transaction.py b/kanta/transaction.py index f947bed..bb56008 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -90,8 +90,8 @@ def transaction( previous = impl.statedict record = impl.queue_change(action, new_dict, user=user, mtime=mtime) if record is not None: - logfmt = _build_logfmt(impl, previous, new_dict) if log is not False: + logfmt = _build_logfmt(impl, previous, new_dict) logger = ( log if isinstance(log, logging.Logger) else transaction_logger ) -- 2.55.0 From f63f6e74c6b571b3a89827d283718e44859ba177 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 14:54:33 +0000 Subject: [PATCH 23/24] Include extra also on transaction abort messages. --- docs/database.md | 3 ++- kanta/logging.py | 7 +++++-- kanta/transaction.py | 1 + tests/test_logemit.py | 3 ++- 4 files changed, 10 insertions(+), 4 deletions(-) diff --git a/docs/database.md b/docs/database.md index 06c8e9f..96e9a3c 100644 --- a/docs/database.md +++ b/docs/database.md @@ -242,7 +242,8 @@ def resolve_user_key(value: str) -> str | None: emitters can reuse as-is or replace piecemeal: - `event.header` ā€” a lazy property producing the default one-line header for any kind: `[ ][ by ]` for changes, - `[ by ] transaction aborted: ` for aborts, and the + `[ ][ by ] transaction aborted: ` for aborts, + and the plain `Created`/`Migrated` summaries. It is settable: assign `event.header = ...` and return truthy to restyle the header while keeping the default diff routing. diff --git a/kanta/logging.py b/kanta/logging.py index 18c4a08..094440d 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -74,8 +74,9 @@ class LogEvent(msgspec.Struct, kw_only=True): """The default one-line header for this event, built on first access. Covers every event kind: ``"[ ][ by ]"`` for - changes, ``"[ by ] transaction aborted: "`` for - aborts, and the plain ``Created``/``Migrated`` summaries. + changes, ``"[ ][ by ] transaction aborted: + "`` for aborts, and the plain ``Created``/``Migrated`` + summaries. """ if self._header is None: self._header = self._build_header() @@ -102,6 +103,8 @@ class LogEvent(msgspec.Struct, kw_only=True): if self.kind == "change": return format_action_header(self.action or "", self.user, self.extra) line = Line().action(self.action or "") + if self.extra: + line(" ").target(self.extra) if self.user: line(" by ").user(self.user) line(f" transaction aborted: {self.error}") diff --git a/kanta/transaction.py b/kanta/transaction.py index bb56008..0f44cae 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -124,6 +124,7 @@ def transaction( kanta=impl._kanta, action=action, user=resolved_user, + extra=extra, error=exc, ), impl.callback_registry.logemit_handlers, diff --git a/tests/test_logemit.py b/tests/test_logemit.py index 9bca8a5..7613627 100644 --- a/tests/test_logemit.py +++ b/tests/test_logemit.py @@ -282,12 +282,13 @@ async def test_aborted_transaction_includes_resolved_user( await kanta.open() with caplog.at_level(logging.WARNING, logger="kanta.transaction"): with pytest.raises(ValueError): - with kanta.transaction(action="reset", user="u1") as data: + with kanta.transaction(action="reset", user="u1", extra="exp") as data: data.counter = 99 raise ValueError("boom") await kanta.close() messages = [r.getMessage() for r in caplog.records if r.levelno == logging.WARNING] + assert any("exp" in m for m in messages) assert any(" by " in m and "Alice" in m for m in messages) assert any(" transaction aborted: boom" in m for m in messages) -- 2.55.0 From 810f379e874796a220ccfbc04c4bef5c680ab565 Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Fri, 7 Aug 2026 15:47:07 +0000 Subject: [PATCH 24/24] Give extra its proper Any typing, handle None vs. 0 vs. empty string gracefully in default formatter. --- docs/database.md | 7 ++++--- kanta/kanta.py | 12 +++++++----- kanta/logging.py | 16 +++++++++------- kanta/transaction.py | 3 ++- 4 files changed, 22 insertions(+), 16 deletions(-) diff --git a/docs/database.md b/docs/database.md index 96e9a3c..5b2cb58 100644 --- a/docs/database.md +++ b/docs/database.md @@ -212,9 +212,10 @@ 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. -- `kanta.transaction(..., extra="...")` accepts a display-only string that is - appended after the action in the header (colored by Kanta); it is never - persisted in the `ChangeRecord`. +- `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 diff --git a/kanta/kanta.py b/kanta/kanta.py index 9422977..6eca545 100644 --- a/kanta/kanta.py +++ b/kanta/kanta.py @@ -5,7 +5,7 @@ import logging from datetime import datetime from pathlib import Path from types import ModuleType, SimpleNamespace -from typing import Generic, TypeVar +from typing import Any, Generic, TypeVar from kanta.kantaimpl import KantaImpl from kanta.serialization import JsonSerializer, Serializer @@ -345,7 +345,7 @@ class Kanta(Generic[T]): action: str, *, user: str | None = None, - extra: str | None = None, + extra: Any = None, mtime: bool | datetime = True, log: bool | logging.Logger = True, logdiff: bool = True, @@ -357,9 +357,11 @@ class Kanta(Generic[T]): user: Optional user identifier stored in metadata and rendered in the log header. Register a ``@kanta.logfmt`` callback to format the user value; the path ``"$user"`` is passed for this case. - extra: Optional display-only string appended after the action in - the log header (colored by Kanta). It is never persisted in - the change record. + extra: Optional display-only value shown after the action in the + log header. Anything other than ``None`` is printed + str-converted (colored by Kanta), unless a custom + ``@kanta.logemit`` handler does something else with it. It is + never persisted in the change record. mtime: Controls the modification time ``m``. ``True`` (default) sets ``m`` to the current UTC time. ``False`` omits ``m`` so the previous modification time remains in effect; this is used for diff --git a/kanta/logging.py b/kanta/logging.py index 094440d..910ea26 100644 --- a/kanta/logging.py +++ b/kanta/logging.py @@ -55,7 +55,7 @@ class LogEvent(msgspec.Struct, kw_only=True): kanta: Any = None action: str | None = None user: str | None = None - extra: str | None = None + extra: Any = None error: BaseException | None = None diff: dict = msgspec.field(default_factory=dict) previous: dict | None = None @@ -413,13 +413,13 @@ def format_diff( def format_action_header( action: str, user: str | None = None, - extra: str | None = None, + extra: Any = None, ) -> str: """Format the default action header line.""" line = Line().action(action) - if extra: + if extra is not None and (extra := f"{extra}"): line(" ").target(extra) - if user: + if user is not None and (user := f"{user}"): line(" by ").user(user) return str(line) @@ -429,7 +429,7 @@ def log_change( diff: dict, user: str | None = None, previous: dict | None = None, - extra: str | None = None, + extra: Any = None, logfmt: Callable[[Any, str], str | None] | None = None, *, logger: logging.Logger = transaction_logger, @@ -447,8 +447,10 @@ def log_change( diff: The JSON diff dict. user: Optional already-formatted user name to show in the header. previous: The previous state dict (for determining add vs update). - extra: Optional display-only string appended after the action in the - header (colored by Kanta). + extra: Optional display-only value 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. logfmt: Optional formatter callable ``(value, path) -> str | None``. logger: Logger to write to. Defaults to the ``kanta.transaction`` logger. level: Log level to use. Defaults to ``logging.INFO``. diff --git a/kanta/transaction.py b/kanta/transaction.py index 0f44cae..bea48a5 100644 --- a/kanta/transaction.py +++ b/kanta/transaction.py @@ -5,6 +5,7 @@ from __future__ import annotations import logging from contextlib import contextmanager from datetime import datetime +from typing import Any from kanta.diff import compute_diff from kanta.exceptions import DataIntegrityError @@ -40,7 +41,7 @@ def transaction( action: str, *, user: str | None = None, - extra: str | None = None, + extra: Any = None, mtime: bool | datetime = True, log: bool | logging.Logger = True, logdiff: bool = True, -- 2.55.0