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.
This commit is contained in:
+2
-5
@@ -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
|
||||
|
||||
@@ -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 <file>`, 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); `.<colorname>` 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=`.
|
||||
|
||||
@@ -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]] = []
|
||||
|
||||
@@ -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,
|
||||
|
||||
+51
-22
@@ -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
|
||||
|
||||
+175
-84
@@ -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 <logger>.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 ``<logger.name>.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),
|
||||
|
||||
+15
-10
@@ -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)
|
||||
|
||||
+181
@@ -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)
|
||||
@@ -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():
|
||||
|
||||
@@ -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)
|
||||
+10
-16
@@ -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):
|
||||
|
||||
@@ -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("é") == 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"
|
||||
Reference in New Issue
Block a user