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