Add separate migration logging, logmigr callback, and log= override
- Split transaction logger (kanta.changes) and migration logger (kanta.migrations). - Migrations.apply() now returns MigrationResult instead of logging. - Kanta.open() emits one info summary per DB and debug transaction per migration. - Add open(log=...) to suppress/redirect default migration logging. - Add @kanta.logmigr callback for custom migration logging/summaries. - Add transaction(log=...) to suppress/redirect transaction logging. - Update tests for the new MigrationResult API and logging behaviour.
This commit is contained in:
+10
-1
@@ -18,6 +18,7 @@ from dataclasses import dataclass
|
|||||||
from typing import Annotated, Any, Union, get_args, get_origin
|
from typing import Annotated, Any, Union, get_args, get_origin
|
||||||
|
|
||||||
from kanta.exceptions import DatabaseError
|
from kanta.exceptions import DatabaseError
|
||||||
|
from kanta.migrations import MigrationResult
|
||||||
|
|
||||||
DictPre = Annotated[dict, "pre"]
|
DictPre = Annotated[dict, "pre"]
|
||||||
DictPost = Annotated[dict, "post"]
|
DictPost = Annotated[dict, "post"]
|
||||||
@@ -59,6 +60,7 @@ class InjectionContext:
|
|||||||
error: DatabaseError | None = None
|
error: DatabaseError | None = None
|
||||||
previous_state: dict | None = None
|
previous_state: dict | None = None
|
||||||
current_state: dict | None = None
|
current_state: dict | None = None
|
||||||
|
migration_result: MigrationResult | None = None
|
||||||
|
|
||||||
|
|
||||||
@dataclass
|
@dataclass
|
||||||
@@ -98,6 +100,7 @@ class CallbackRegistry:
|
|||||||
self._callbacks: dict[str, list[_CallbackRegistration]] = {
|
self._callbacks: dict[str, list[_CallbackRegistration]] = {
|
||||||
"bootstrap": [],
|
"bootstrap": [],
|
||||||
"fatal_error": [],
|
"fatal_error": [],
|
||||||
|
"logmigr": [],
|
||||||
}
|
}
|
||||||
self._logfmt_callbacks: list[_LogFmtFunctionSpec | _LogFmtClassSpec] = []
|
self._logfmt_callbacks: list[_LogFmtFunctionSpec | _LogFmtClassSpec] = []
|
||||||
|
|
||||||
@@ -446,10 +449,12 @@ class CallbackRegistry:
|
|||||||
return kind == "logfmt"
|
return kind == "logfmt"
|
||||||
if bare is DatabaseError:
|
if bare is DatabaseError:
|
||||||
return kind == "fatal_error"
|
return kind == "fatal_error"
|
||||||
|
if bare is MigrationResult:
|
||||||
|
return kind == "logmigr"
|
||||||
if self._data_type is not None and bare is self._data_type:
|
if self._data_type is not None and bare is self._data_type:
|
||||||
return kind == "bootstrap"
|
return kind == "bootstrap"
|
||||||
if self._kanta_class is not None and bare is self._kanta_class:
|
if self._kanta_class is not None and bare is self._kanta_class:
|
||||||
return kind in {"bootstrap", "fatal_error", "logfmt"}
|
return kind in {"bootstrap", "fatal_error", "logfmt", "logmigr"}
|
||||||
return False
|
return False
|
||||||
|
|
||||||
def _allowed_message(self, kind: str) -> str:
|
def _allowed_message(self, kind: str) -> str:
|
||||||
@@ -462,6 +467,8 @@ class CallbackRegistry:
|
|||||||
parts.append(self._kanta_class.__name__)
|
parts.append(self._kanta_class.__name__)
|
||||||
if kind == "fatal_error":
|
if kind == "fatal_error":
|
||||||
parts.append("DatabaseError")
|
parts.append("DatabaseError")
|
||||||
|
if kind == "logmigr":
|
||||||
|
parts.append("MigrationResult")
|
||||||
if kind == "logfmt":
|
if kind == "logfmt":
|
||||||
parts.append("Annotated[dict, 'pre']")
|
parts.append("Annotated[dict, 'pre']")
|
||||||
parts.append("Annotated[dict, 'post']")
|
parts.append("Annotated[dict, 'post']")
|
||||||
@@ -475,6 +482,8 @@ class CallbackRegistry:
|
|||||||
return ctx.current_state
|
return ctx.current_state
|
||||||
if bare is DatabaseError:
|
if bare is DatabaseError:
|
||||||
return ctx.error
|
return ctx.error
|
||||||
|
if bare is MigrationResult:
|
||||||
|
return ctx.migration_result
|
||||||
if self._data_type is not None and bare is self._data_type:
|
if self._data_type is not None and bare is self._data_type:
|
||||||
return ctx.data
|
return ctx.data
|
||||||
if self._kanta_class is not None and bare is self._kanta_class:
|
if self._kanta_class is not None and bare is self._kanta_class:
|
||||||
|
|||||||
+38
-2
@@ -1,6 +1,7 @@
|
|||||||
"""Kanta DB main public API"""
|
"""Kanta DB main public API"""
|
||||||
|
|
||||||
from __future__ import annotations
|
from __future__ import annotations
|
||||||
|
import logging
|
||||||
from datetime import datetime
|
from datetime import datetime
|
||||||
from pathlib import Path
|
from pathlib import Path
|
||||||
from types import ModuleType, SimpleNamespace
|
from types import ModuleType, SimpleNamespace
|
||||||
@@ -144,7 +145,13 @@ class Kanta(Generic[T]):
|
|||||||
"""
|
"""
|
||||||
return self._impl.mtime
|
return self._impl.mtime
|
||||||
|
|
||||||
async def open(self, *, create: bool = True, readonly: bool = False) -> None:
|
async def open(
|
||||||
|
self,
|
||||||
|
*,
|
||||||
|
create: bool = True,
|
||||||
|
readonly: bool = False,
|
||||||
|
log: bool | logging.Logger = True,
|
||||||
|
) -> None:
|
||||||
"""Open the database file and start background persistence.
|
"""Open the database file and start background persistence.
|
||||||
|
|
||||||
This loads existing records, applies configured migrations, and starts
|
This loads existing records, applies configured migrations, and starts
|
||||||
@@ -156,6 +163,11 @@ class Kanta(Generic[T]):
|
|||||||
readonly: If True, open the database read-only. No lock is acquired,
|
readonly: If True, open the database read-only. No lock is acquired,
|
||||||
no background flush task is started, and transactions are
|
no background flush task is started, and transactions are
|
||||||
rejected. The file is not created if missing.
|
rejected. The file is not created if missing.
|
||||||
|
log: Controls migration logging. ``True`` (default) uses the
|
||||||
|
``kanta.migrations`` logger. ``False`` suppresses the default
|
||||||
|
migration log. A :class:`~logging.Logger` instance writes
|
||||||
|
default migration output to that logger instead. Custom
|
||||||
|
``@kanta.logmigr`` callbacks run regardless of this setting.
|
||||||
|
|
||||||
Calling ``open`` more than once on the same instance is not allowed.
|
Calling ``open`` more than once on the same instance is not allowed.
|
||||||
|
|
||||||
@@ -163,7 +175,7 @@ class Kanta(Generic[T]):
|
|||||||
kanta.exceptions.DatabaseError: If replay or decoding fails.
|
kanta.exceptions.DatabaseError: If replay or decoding fails.
|
||||||
kanta.exceptions.DataIntegrityError: If the instance is already open.
|
kanta.exceptions.DataIntegrityError: If the instance is already open.
|
||||||
"""
|
"""
|
||||||
await self._impl.open(create=create, readonly=readonly)
|
await self._impl.open(create=create, readonly=readonly, log=log)
|
||||||
|
|
||||||
async def __aenter__(self) -> Kanta[T]:
|
async def __aenter__(self) -> Kanta[T]:
|
||||||
"""Enter async context manager and open the database.
|
"""Enter async context manager and open the database.
|
||||||
@@ -239,6 +251,24 @@ class Kanta(Generic[T]):
|
|||||||
return _register
|
return _register
|
||||||
return _register(fn)
|
return _register(fn)
|
||||||
|
|
||||||
|
def logmigr(self, fn=None):
|
||||||
|
"""Register a migration logging callback.
|
||||||
|
|
||||||
|
Can be used as ``@kanta.logmigr``.
|
||||||
|
The callback receives a :class:`kanta.migrations.MigrationResult` and
|
||||||
|
may be sync or async. If registered, it replaces the default migration
|
||||||
|
logger output; the application is responsible for emitting any log
|
||||||
|
messages.
|
||||||
|
"""
|
||||||
|
|
||||||
|
def _register(callback):
|
||||||
|
self._impl.add_logmigr(callback)
|
||||||
|
return callback
|
||||||
|
|
||||||
|
if fn is None:
|
||||||
|
return _register
|
||||||
|
return _register(fn)
|
||||||
|
|
||||||
def logfmt(self, fn=None, *, path: str | None = None):
|
def logfmt(self, fn=None, *, path: str | None = None):
|
||||||
"""Register a transaction logfmt callback.
|
"""Register a transaction logfmt callback.
|
||||||
|
|
||||||
@@ -266,6 +296,7 @@ class Kanta(Generic[T]):
|
|||||||
*,
|
*,
|
||||||
user: str | None = None,
|
user: str | None = None,
|
||||||
mtime: bool | datetime = True,
|
mtime: bool | datetime = True,
|
||||||
|
log: bool | logging.Logger = True,
|
||||||
):
|
):
|
||||||
"""Create a transactional mutation context manager.
|
"""Create a transactional mutation context manager.
|
||||||
|
|
||||||
@@ -280,6 +311,10 @@ class Kanta(Generic[T]):
|
|||||||
system operations that are not considered modifications. A
|
system operations that are not considered modifications. A
|
||||||
:class:`~datetime.datetime` value sets ``m`` to that explicit
|
:class:`~datetime.datetime` value sets ``m`` to that explicit
|
||||||
time.
|
time.
|
||||||
|
log: Controls transaction logging. ``True`` (default) uses the
|
||||||
|
``kanta.changes`` logger. ``False`` suppresses the transaction
|
||||||
|
log. A :class:`~logging.Logger` instance writes output to that
|
||||||
|
logger instead.
|
||||||
|
|
||||||
Returns:
|
Returns:
|
||||||
A context manager yielding the live state object for mutation.
|
A context manager yielding the live state object for mutation.
|
||||||
@@ -294,4 +329,5 @@ class Kanta(Generic[T]):
|
|||||||
action,
|
action,
|
||||||
user=user,
|
user=user,
|
||||||
mtime=mtime,
|
mtime=mtime,
|
||||||
|
log=log,
|
||||||
)
|
)
|
||||||
|
|||||||
+79
-9
@@ -12,7 +12,8 @@ from typing import Any, Generic, TypeVar
|
|||||||
|
|
||||||
from kanta.callbacks import CallbackRegistry, InjectionContext
|
from kanta.callbacks import CallbackRegistry, InjectionContext
|
||||||
from kanta.exceptions import DatabaseError, DataIntegrityError, ReplayError
|
from kanta.exceptions import DatabaseError, DataIntegrityError, ReplayError
|
||||||
from kanta.migrations import Migrations
|
from kanta.logging import log_change, migration_logger
|
||||||
|
from kanta.migrations import MigrationResult, Migrations
|
||||||
from kanta.persistence import PersistenceMixin
|
from kanta.persistence import PersistenceMixin
|
||||||
from kanta.serialization import restore_data_in_place, struct_to_dict
|
from kanta.serialization import restore_data_in_place, struct_to_dict
|
||||||
from kanta.serialization.base import replay
|
from kanta.serialization.base import replay
|
||||||
@@ -75,7 +76,64 @@ class KantaImpl(PersistenceMixin, Generic[T]):
|
|||||||
"""Register one transaction logfmt callback."""
|
"""Register one transaction logfmt callback."""
|
||||||
self.callback_registry.register("logfmt", callback, path=path)
|
self.callback_registry.register("logfmt", callback, path=path)
|
||||||
|
|
||||||
async def open(self, *, create: bool = True, readonly: bool = False) -> None:
|
def add_logmigr(self, callback) -> None:
|
||||||
|
"""Register one migration logging callback."""
|
||||||
|
self.callback_registry.register("logmigr", callback)
|
||||||
|
|
||||||
|
async def _handle_migration_log(
|
||||||
|
self,
|
||||||
|
migration_result: MigrationResult,
|
||||||
|
previous_version: int,
|
||||||
|
log: bool | logging.Logger,
|
||||||
|
) -> None:
|
||||||
|
"""Route migration logging to callback or default logger."""
|
||||||
|
assert isinstance(migration_result, MigrationResult)
|
||||||
|
|
||||||
|
if self.callback_registry.has("logmigr"):
|
||||||
|
await self.callback_registry.invoke(
|
||||||
|
"logmigr",
|
||||||
|
InjectionContext(
|
||||||
|
kanta=self._kanta,
|
||||||
|
migration_result=migration_result,
|
||||||
|
),
|
||||||
|
)
|
||||||
|
return
|
||||||
|
|
||||||
|
if log is False:
|
||||||
|
return
|
||||||
|
|
||||||
|
migration_log = log if isinstance(log, logging.Logger) else migration_logger
|
||||||
|
|
||||||
|
changed = [m for m in migration_result.migrations if m.changed]
|
||||||
|
if not changed:
|
||||||
|
return
|
||||||
|
|
||||||
|
for info in changed:
|
||||||
|
if info.diff:
|
||||||
|
log_change(
|
||||||
|
info.name,
|
||||||
|
info.diff,
|
||||||
|
previous=info.before,
|
||||||
|
logger=migration_log,
|
||||||
|
level=logging.DEBUG,
|
||||||
|
)
|
||||||
|
|
||||||
|
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),
|
||||||
|
)
|
||||||
|
|
||||||
|
async def open(
|
||||||
|
self,
|
||||||
|
*,
|
||||||
|
create: bool = True,
|
||||||
|
readonly: bool = False,
|
||||||
|
log: bool | logging.Logger = True,
|
||||||
|
) -> None:
|
||||||
"""Open the database: load from disk, apply migrations, start background task."""
|
"""Open the database: load from disk, apply migrations, start background task."""
|
||||||
if self.opened:
|
if self.opened:
|
||||||
raise DataIntegrityError(
|
raise DataIntegrityError(
|
||||||
@@ -142,13 +200,21 @@ class KantaImpl(PersistenceMixin, Generic[T]):
|
|||||||
cause_type=type(e).__name__,
|
cause_type=type(e).__name__,
|
||||||
) from e
|
) from e
|
||||||
|
|
||||||
migrations_ran = False
|
migration_result = None
|
||||||
state_before_migrations = None
|
state_before_migrations = None
|
||||||
|
previous_version = rr.version
|
||||||
if self.migrations is not None:
|
if self.migrations is not None:
|
||||||
previous_version = rr.version
|
|
||||||
state_before_migrations = copy.deepcopy(rr.state)
|
state_before_migrations = copy.deepcopy(rr.state)
|
||||||
rr.version = self.migrations.apply(rr.state, rr.version, self._kanta)
|
migration_result = self.migrations.apply(
|
||||||
migrations_ran = rr.version != previous_version
|
rr.state, rr.version, self._kanta
|
||||||
|
)
|
||||||
|
rr.version = migration_result.version
|
||||||
|
|
||||||
|
migrations_ran = rr.version != previous_version
|
||||||
|
migration_state_changed = (
|
||||||
|
state_before_migrations is not None
|
||||||
|
and state_before_migrations != rr.state
|
||||||
|
)
|
||||||
|
|
||||||
self.snapshot.ts = (
|
self.snapshot.ts = (
|
||||||
datetime.fromtimestamp(rr.last_snapshot_mtime, UTC)
|
datetime.fromtimestamp(rr.last_snapshot_mtime, UTC)
|
||||||
@@ -173,9 +239,8 @@ class KantaImpl(PersistenceMixin, Generic[T]):
|
|||||||
if self.readonly:
|
if self.readonly:
|
||||||
self.statedict = copy.deepcopy(normalized)
|
self.statedict = copy.deepcopy(normalized)
|
||||||
else:
|
else:
|
||||||
migration_record = None
|
if migrations_ran and migration_state_changed:
|
||||||
if migrations_ran and self.statedict != rr.state:
|
self.queue_change(
|
||||||
migration_record = self.queue_change(
|
|
||||||
f"migrate:v{self.version}",
|
f"migrate:v{self.version}",
|
||||||
rr.state,
|
rr.state,
|
||||||
mtime=False,
|
mtime=False,
|
||||||
@@ -189,6 +254,11 @@ class KantaImpl(PersistenceMixin, Generic[T]):
|
|||||||
self.snapshot.maybe_write(
|
self.snapshot.maybe_write(
|
||||||
self.file, self.version, self.statedict, m=self.mtime
|
self.file, self.version, self.statedict, m=self.mtime
|
||||||
)
|
)
|
||||||
|
|
||||||
|
if migrations_ran and migration_result is not None:
|
||||||
|
await self._handle_migration_log(
|
||||||
|
migration_result, previous_version, log
|
||||||
|
)
|
||||||
elif self.readonly:
|
elif self.readonly:
|
||||||
self.opened = False
|
self.opened = False
|
||||||
self.file.close()
|
self.file.close()
|
||||||
|
|||||||
+15
-9
@@ -10,7 +10,8 @@ import sys
|
|||||||
from collections.abc import Callable
|
from collections.abc import Callable
|
||||||
from typing import Any
|
from typing import Any
|
||||||
|
|
||||||
logger = logging.getLogger("kanta.changes")
|
changes_logger = logging.getLogger("kanta.changes")
|
||||||
|
migration_logger = logging.getLogger("kanta.migrations")
|
||||||
|
|
||||||
# Pattern to match control characters and bidirectional overrides
|
# Pattern to match control characters and bidirectional overrides
|
||||||
_UNSAFE_CHARS = re.compile(
|
_UNSAFE_CHARS = re.compile(
|
||||||
@@ -274,6 +275,9 @@ def log_change(
|
|||||||
user: str | None = None,
|
user: str | None = None,
|
||||||
previous: dict | None = None,
|
previous: dict | None = None,
|
||||||
logfmt: Callable[[Any, str], str | None] | None = None,
|
logfmt: Callable[[Any, str], str | None] | None = None,
|
||||||
|
*,
|
||||||
|
logger: logging.Logger = changes_logger,
|
||||||
|
level: int = logging.INFO,
|
||||||
) -> None:
|
) -> None:
|
||||||
"""Log a database change with pretty-printed diff.
|
"""Log a database change with pretty-printed diff.
|
||||||
|
|
||||||
@@ -283,27 +287,29 @@ def log_change(
|
|||||||
user: Optional already-formatted user name to show in the header.
|
user: Optional already-formatted user name to show in the header.
|
||||||
previous: The previous state dict (for determining add vs update).
|
previous: The previous state dict (for determining add vs update).
|
||||||
logfmt: Optional formatter callable ``(value, path) -> str | None``.
|
logfmt: Optional formatter callable ``(value, path) -> str | None``.
|
||||||
|
logger: Logger to write to. Defaults to the ``kanta.changes`` logger.
|
||||||
|
level: Log level to use. Defaults to ``logging.INFO``.
|
||||||
"""
|
"""
|
||||||
header = format_action_header(action, user)
|
header = format_action_header(action, user)
|
||||||
diff_lines = format_diff(diff, previous, logfmt)
|
diff_lines = format_diff(diff, previous, logfmt)
|
||||||
|
|
||||||
if not diff_lines:
|
if not diff_lines:
|
||||||
logger.info(header)
|
logger.log(level, header)
|
||||||
return
|
return
|
||||||
|
|
||||||
if len(diff_lines) == 1:
|
if len(diff_lines) == 1:
|
||||||
logger.info(f"{header}{diff_lines[0]}")
|
logger.log(level, f"{header}{diff_lines[0]}")
|
||||||
else:
|
else:
|
||||||
logger.info(header)
|
logger.log(level, header)
|
||||||
for line in diff_lines:
|
for line in diff_lines:
|
||||||
logger.info(line)
|
logger.log(level, line)
|
||||||
|
|
||||||
|
|
||||||
def configure_logging() -> None:
|
def configure_logging() -> None:
|
||||||
"""Configure the database logger to output to stderr without prefix."""
|
"""Configure the database logger to output to stderr without prefix."""
|
||||||
if not logger.handlers:
|
if not changes_logger.handlers:
|
||||||
handler = logging.StreamHandler(sys.stderr)
|
handler = logging.StreamHandler(sys.stderr)
|
||||||
handler.setFormatter(logging.Formatter("%(message)s"))
|
handler.setFormatter(logging.Formatter("%(message)s"))
|
||||||
logger.addHandler(handler)
|
changes_logger.addHandler(handler)
|
||||||
logger.setLevel(logging.INFO)
|
changes_logger.setLevel(logging.INFO)
|
||||||
logger.propagate = False
|
changes_logger.propagate = False
|
||||||
|
|||||||
+44
-14
@@ -9,19 +9,38 @@ from __future__ import annotations
|
|||||||
import copy
|
import copy
|
||||||
import importlib
|
import importlib
|
||||||
import inspect
|
import inspect
|
||||||
import logging
|
from dataclasses import dataclass
|
||||||
from types import ModuleType
|
from types import ModuleType
|
||||||
from typing import Any
|
from typing import Any
|
||||||
|
|
||||||
|
from kanta.diff import compute_diff
|
||||||
from kanta.exceptions import DatabaseError
|
from kanta.exceptions import DatabaseError
|
||||||
|
|
||||||
_logger = logging.getLogger(__name__)
|
|
||||||
|
|
||||||
# Cache registries by imported module object so that many Kanta instances using
|
# Cache registries by imported module object so that many Kanta instances using
|
||||||
# the same migrations module do not re-scan it each time.
|
# the same migrations module do not re-scan it each time.
|
||||||
_module_registry_cache: dict[ModuleType, Migrations] = {}
|
_module_registry_cache: dict[ModuleType, Migrations] = {}
|
||||||
|
|
||||||
|
|
||||||
|
@dataclass
|
||||||
|
class MigrationInfo:
|
||||||
|
"""Information about a single migration that ran."""
|
||||||
|
|
||||||
|
name: str
|
||||||
|
description: str
|
||||||
|
version: int
|
||||||
|
changed: bool
|
||||||
|
diff: dict | None = None
|
||||||
|
before: dict | None = None
|
||||||
|
|
||||||
|
|
||||||
|
@dataclass
|
||||||
|
class MigrationResult:
|
||||||
|
"""Result of applying migrations."""
|
||||||
|
|
||||||
|
version: int
|
||||||
|
migrations: list[MigrationInfo]
|
||||||
|
|
||||||
|
|
||||||
class Migrations:
|
class Migrations:
|
||||||
"""Registry of schema migration functions.
|
"""Registry of schema migration functions.
|
||||||
|
|
||||||
@@ -38,12 +57,13 @@ class Migrations:
|
|||||||
def migrate_v2(d: dict) -> None:
|
def migrate_v2(d: dict) -> None:
|
||||||
d.setdefault("version", 2)
|
d.setdefault("version", 2)
|
||||||
|
|
||||||
new_version = migrations.apply(state, current_version=0, kanta=kanta)
|
result = migrations.apply(state, current_version=0, kanta=kanta)
|
||||||
|
new_version = result.version
|
||||||
|
|
||||||
Or load from a module::
|
Or load from a module::
|
||||||
|
|
||||||
migrations = Migrations.from_module("myapp.migrations")
|
migrations = Migrations.from_module("myapp.migrations")
|
||||||
new_version = migrations.apply(state, current_version=0, kanta=kanta)
|
result = migrations.apply(state, current_version=0, kanta=kanta)
|
||||||
"""
|
"""
|
||||||
|
|
||||||
def __init__(self) -> None:
|
def __init__(self) -> None:
|
||||||
@@ -117,9 +137,7 @@ class Migrations:
|
|||||||
data_dict: dict[str, Any],
|
data_dict: dict[str, Any],
|
||||||
current_version: int,
|
current_version: int,
|
||||||
kanta: Any,
|
kanta: Any,
|
||||||
*,
|
) -> MigrationResult:
|
||||||
silent: bool = False,
|
|
||||||
) -> int:
|
|
||||||
"""Apply pending migrations to *data_dict* in place.
|
"""Apply pending migrations to *data_dict* in place.
|
||||||
|
|
||||||
Missing intermediate migration steps are silently skipped.
|
Missing intermediate migration steps are silently skipped.
|
||||||
@@ -128,7 +146,8 @@ class Migrations:
|
|||||||
DatabaseError: If the database version is newer than the highest
|
DatabaseError: If the database version is newer than the highest
|
||||||
supported version or older than the minimum supported version.
|
supported version or older than the minimum supported version.
|
||||||
|
|
||||||
Returns the new version after all migrations.
|
Returns a :class:`MigrationResult` describing the new version and every
|
||||||
|
migration that ran.
|
||||||
"""
|
"""
|
||||||
if current_version > self.dbver:
|
if current_version > self.dbver:
|
||||||
raise DatabaseError(
|
raise DatabaseError(
|
||||||
@@ -141,14 +160,25 @@ class Migrations:
|
|||||||
f"minimum supported version v{self.minver}"
|
f"minimum supported version v{self.minver}"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
migrations: list[MigrationInfo] = []
|
||||||
for version in sorted(self._migrations.keys()):
|
for version in sorted(self._migrations.keys()):
|
||||||
if version <= current_version:
|
if version <= current_version:
|
||||||
continue
|
continue
|
||||||
fn = self._migrations[version]
|
fn = self._migrations[version]
|
||||||
before = copy.deepcopy(data_dict) if not silent else None
|
before = copy.deepcopy(data_dict)
|
||||||
self._call_migration(fn, data_dict, kanta)
|
self._call_migration(fn, data_dict, kanta)
|
||||||
current_version = version
|
current_version = version
|
||||||
if not silent and before != data_dict:
|
changed = before != data_dict
|
||||||
desc = (fn.__doc__ or fn.__name__).split("\n")[0].rstrip(".")
|
diff = compute_diff(before, data_dict) if changed else None
|
||||||
_logger.info("Applied migration %s: %s", fn.__name__, desc)
|
desc = (fn.__doc__ or f"v{version}").split("\n")[0].rstrip(".")
|
||||||
return current_version
|
migrations.append(
|
||||||
|
MigrationInfo(
|
||||||
|
name=fn.__name__,
|
||||||
|
description=desc,
|
||||||
|
version=version,
|
||||||
|
changed=changed,
|
||||||
|
diff=diff,
|
||||||
|
before=before,
|
||||||
|
)
|
||||||
|
)
|
||||||
|
return MigrationResult(version=current_version, migrations=migrations)
|
||||||
|
|||||||
+12
-2
@@ -9,7 +9,7 @@ from datetime import datetime
|
|||||||
from kanta.diff import compute_diff
|
from kanta.diff import compute_diff
|
||||||
from kanta.exceptions import DataIntegrityError
|
from kanta.exceptions import DataIntegrityError
|
||||||
from kanta.callbacks import InjectionContext
|
from kanta.callbacks import InjectionContext
|
||||||
from kanta.logging import _USER_PATH, log_change
|
from kanta.logging import _USER_PATH, changes_logger, log_change
|
||||||
from kanta.serialization import restore_data_in_place, struct_to_dict
|
from kanta.serialization import restore_data_in_place, struct_to_dict
|
||||||
|
|
||||||
_logger = logging.getLogger(__name__)
|
_logger = logging.getLogger(__name__)
|
||||||
@@ -22,6 +22,7 @@ def transaction(
|
|||||||
*,
|
*,
|
||||||
user: str | None = None,
|
user: str | None = None,
|
||||||
mtime: bool | datetime = True,
|
mtime: bool | datetime = True,
|
||||||
|
log: bool | logging.Logger = True,
|
||||||
):
|
):
|
||||||
"""Wrap writes in a transaction and yield the live db object."""
|
"""Wrap writes in a transaction and yield the live db object."""
|
||||||
if impl.readonly:
|
if impl.readonly:
|
||||||
@@ -80,7 +81,16 @@ def transaction(
|
|||||||
resolved = logfmt(user, _USER_PATH)
|
resolved = logfmt(user, _USER_PATH)
|
||||||
if resolved is not None:
|
if resolved is not None:
|
||||||
formatted_user = resolved
|
formatted_user = resolved
|
||||||
log_change(action, record.diff, formatted_user, previous, logfmt)
|
if log is not False:
|
||||||
|
logger = log if isinstance(log, logging.Logger) else changes_logger
|
||||||
|
log_change(
|
||||||
|
action,
|
||||||
|
record.diff,
|
||||||
|
formatted_user,
|
||||||
|
previous,
|
||||||
|
logfmt,
|
||||||
|
logger=logger,
|
||||||
|
)
|
||||||
except Exception:
|
except Exception:
|
||||||
_logger.warning("Transaction '%s' failed, rolling back changes", action)
|
_logger.warning("Transaction '%s' failed, rolling back changes", action)
|
||||||
if impl.transaction_snapshot is not None:
|
if impl.transaction_snapshot is not None:
|
||||||
|
|||||||
@@ -1,4 +1,5 @@
|
|||||||
import asyncio
|
import asyncio
|
||||||
|
import logging
|
||||||
import sys
|
import sys
|
||||||
from datetime import UTC, datetime
|
from datetime import UTC, datetime
|
||||||
from uuid import uuid4
|
from uuid import uuid4
|
||||||
@@ -6,6 +7,7 @@ from uuid import uuid4
|
|||||||
import pytest
|
import pytest
|
||||||
|
|
||||||
from kanta.exceptions import DatabaseError, DataIntegrityError, FileLockError
|
from kanta.exceptions import DatabaseError, DataIntegrityError, FileLockError
|
||||||
|
from kanta.migrations import MigrationResult
|
||||||
from kanta.serialization import struct_to_dict
|
from kanta.serialization import struct_to_dict
|
||||||
|
|
||||||
from .support import (
|
from .support import (
|
||||||
@@ -72,9 +74,7 @@ async def test_new_file_persists_initial_state_for_roundtrip(tmp_path, format_co
|
|||||||
|
|
||||||
|
|
||||||
@pytest.mark.asyncio
|
@pytest.mark.asyncio
|
||||||
async def test_reopen_without_changes_does_not_force_snapshot(
|
async def test_reopen_without_changes_does_not_force_snapshot(tmp_path, format_config):
|
||||||
tmp_path, format_config
|
|
||||||
):
|
|
||||||
path = tmp_path / "test.db"
|
path = tmp_path / "test.db"
|
||||||
kanta = make_kanta(path, Data(counter=5), format_config)
|
kanta = make_kanta(path, Data(counter=5), format_config)
|
||||||
await kanta.open()
|
await kanta.open()
|
||||||
@@ -576,6 +576,123 @@ async def test_migration_with_changes_records_diff_and_snapshot(
|
|||||||
assert snap.state == {"counter": 2, "users": {}}
|
assert snap.state == {"counter": 2, "users": {}}
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.asyncio
|
||||||
|
async def test_migration_summary_log_includes_filename(tmp_path, format_config, caplog):
|
||||||
|
path = tmp_path / "test.db"
|
||||||
|
seed_single_change(path, fixed_change("init", {"counter": 0}), format_config)
|
||||||
|
|
||||||
|
mod = type(sys)("test_migrations_log")
|
||||||
|
|
||||||
|
def migrate_v1(d, kanta):
|
||||||
|
"""Bump counter."""
|
||||||
|
d["counter"] = 2
|
||||||
|
|
||||||
|
mod.__dict__["migrate_v1"] = migrate_v1
|
||||||
|
|
||||||
|
with caplog.at_level(logging.INFO, logger="kanta.migrations"):
|
||||||
|
kanta = make_kanta(path, Data, format_config, migrations=mod)
|
||||||
|
await kanta.open()
|
||||||
|
assert kanta.version == 1
|
||||||
|
await kanta.close()
|
||||||
|
|
||||||
|
info_messages = [r.message for r in caplog.records if r.levelno == logging.INFO]
|
||||||
|
assert len(info_messages) == 1
|
||||||
|
assert str(path) in info_messages[0]
|
||||||
|
assert "v0 -> v1" in info_messages[0]
|
||||||
|
assert "migrate_v1 (Bump counter)" in info_messages[0]
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.asyncio
|
||||||
|
async def test_open_log_false_suppresses_migration_log(tmp_path, format_config, caplog):
|
||||||
|
path = tmp_path / "test.db"
|
||||||
|
seed_single_change(path, fixed_change("init", {"counter": 0}), format_config)
|
||||||
|
|
||||||
|
mod = type(sys)("test_migrations_silent")
|
||||||
|
|
||||||
|
def migrate_v1(d, kanta):
|
||||||
|
d["counter"] = 2
|
||||||
|
|
||||||
|
mod.__dict__["migrate_v1"] = migrate_v1
|
||||||
|
|
||||||
|
with caplog.at_level(logging.INFO, logger="kanta.migrations"):
|
||||||
|
kanta = make_kanta(path, Data, format_config, migrations=mod)
|
||||||
|
await kanta.open(log=False)
|
||||||
|
await kanta.close()
|
||||||
|
|
||||||
|
info_messages = [r for r in caplog.records if r.levelno == logging.INFO]
|
||||||
|
assert not info_messages
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.asyncio
|
||||||
|
async def test_logmigr_callback_replaces_default_logging(
|
||||||
|
tmp_path, format_config, caplog
|
||||||
|
):
|
||||||
|
path = tmp_path / "test.db"
|
||||||
|
seed_single_change(path, fixed_change("init", {"counter": 0}), format_config)
|
||||||
|
|
||||||
|
mod = type(sys)("test_migrations_callback")
|
||||||
|
|
||||||
|
def migrate_v1(d, kanta):
|
||||||
|
"""Bump counter."""
|
||||||
|
d["counter"] = 2
|
||||||
|
|
||||||
|
mod.__dict__["migrate_v1"] = migrate_v1
|
||||||
|
|
||||||
|
summaries = []
|
||||||
|
|
||||||
|
kanta = make_kanta(path, Data, format_config, migrations=mod)
|
||||||
|
|
||||||
|
@kanta.logmigr
|
||||||
|
def collect(summary: MigrationResult):
|
||||||
|
summaries.append(summary)
|
||||||
|
|
||||||
|
with caplog.at_level(logging.INFO, logger="kanta.migrations"):
|
||||||
|
await kanta.open()
|
||||||
|
await kanta.close()
|
||||||
|
|
||||||
|
assert len(summaries) == 1
|
||||||
|
assert summaries[0].version == 1
|
||||||
|
assert summaries[0].migrations[0].name == "migrate_v1"
|
||||||
|
info_messages = [r for r in caplog.records if r.levelno == logging.INFO]
|
||||||
|
assert not info_messages
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.asyncio
|
||||||
|
async def test_transaction_log_false_suppresses_log(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.changes"):
|
||||||
|
with kanta.transaction(action="inc", log=False) as data:
|
||||||
|
data.counter = 1
|
||||||
|
|
||||||
|
await kanta.close()
|
||||||
|
|
||||||
|
info_messages = [r for r in caplog.records if r.levelno == logging.INFO]
|
||||||
|
assert not info_messages
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.asyncio
|
||||||
|
async def test_transaction_log_custom_logger(tmp_path, format_config, caplog):
|
||||||
|
path = tmp_path / "test.db"
|
||||||
|
kanta = make_kanta(path, Data, format_config)
|
||||||
|
await kanta.open()
|
||||||
|
|
||||||
|
custom_logger = logging.getLogger("custom.transaction")
|
||||||
|
custom_logger.setLevel(logging.INFO)
|
||||||
|
|
||||||
|
with caplog.at_level(logging.INFO, logger="custom.transaction"):
|
||||||
|
with kanta.transaction(action="inc", log=custom_logger) as data:
|
||||||
|
data.counter = 1
|
||||||
|
|
||||||
|
await kanta.close()
|
||||||
|
|
||||||
|
info_messages = [r for r in caplog.records if r.levelno == logging.INFO]
|
||||||
|
assert len(info_messages) >= 1
|
||||||
|
assert "inc" in info_messages[0].message
|
||||||
|
|
||||||
|
|
||||||
@pytest.mark.asyncio
|
@pytest.mark.asyncio
|
||||||
async def test_open_locked_file_raises_filelock_error(tmp_path, format_config):
|
async def test_open_locked_file_raises_filelock_error(tmp_path, format_config):
|
||||||
path = tmp_path / "test.db"
|
path = tmp_path / "test.db"
|
||||||
|
|||||||
@@ -1,16 +1,15 @@
|
|||||||
import logging
|
import logging
|
||||||
|
|
||||||
from kanta.logging import configure_logging, log_change
|
from kanta.logging import changes_logger, configure_logging, log_change
|
||||||
from kanta.logging import logger
|
|
||||||
|
|
||||||
|
|
||||||
def test_configure_logging():
|
def test_configure_logging():
|
||||||
configure_logging()
|
configure_logging()
|
||||||
assert logger.level == logging.INFO
|
assert changes_logger.level == logging.INFO
|
||||||
|
|
||||||
|
|
||||||
def test_log_change_no_diff(capsys):
|
def test_log_change_no_diff(capsys):
|
||||||
logger.handlers.clear()
|
changes_logger.handlers.clear()
|
||||||
configure_logging()
|
configure_logging()
|
||||||
log_change("test", {})
|
log_change("test", {})
|
||||||
captured = capsys.readouterr()
|
captured = capsys.readouterr()
|
||||||
|
|||||||
+38
-34
@@ -1,4 +1,3 @@
|
|||||||
import logging
|
|
||||||
from types import ModuleType, SimpleNamespace
|
from types import ModuleType, SimpleNamespace
|
||||||
|
|
||||||
import pytest
|
import pytest
|
||||||
@@ -25,8 +24,8 @@ def test_register_and_apply():
|
|||||||
d["version"] = 2
|
d["version"] = 2
|
||||||
|
|
||||||
state = {}
|
state = {}
|
||||||
new_ver = reg.apply(state, current_version=0, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=0, kanta=kanta)
|
||||||
assert new_ver == 2
|
assert result.version == 2
|
||||||
assert state["version"] == 2
|
assert state["version"] == 2
|
||||||
|
|
||||||
|
|
||||||
@@ -39,8 +38,8 @@ def test_no_migrations_needed():
|
|||||||
d["x"] = 1
|
d["x"] = 1
|
||||||
|
|
||||||
state = {"x": 1}
|
state = {"x": 1}
|
||||||
new_ver = reg.apply(state, current_version=1, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=1, kanta=kanta)
|
||||||
assert new_ver == 1
|
assert result.version == 1
|
||||||
|
|
||||||
|
|
||||||
def test_from_module():
|
def test_from_module():
|
||||||
@@ -60,8 +59,8 @@ def test_from_module():
|
|||||||
assert reg.dbver == 2
|
assert reg.dbver == 2
|
||||||
|
|
||||||
state = {}
|
state = {}
|
||||||
new_ver = reg.apply(state, current_version=0, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=0, kanta=kanta)
|
||||||
assert new_ver == 2
|
assert result.version == 2
|
||||||
assert state["v"] == 2
|
assert state["v"] == 2
|
||||||
|
|
||||||
|
|
||||||
@@ -75,8 +74,8 @@ def test_migrations_can_use_kanta_ctx():
|
|||||||
d["source"] = kanta.ctx.source
|
d["source"] = kanta.ctx.source
|
||||||
|
|
||||||
state = {}
|
state = {}
|
||||||
new_ver = reg.apply(state, current_version=0, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=0, kanta=kanta)
|
||||||
assert new_ver == 1
|
assert result.version == 1
|
||||||
assert state["source"] == "migration"
|
assert state["source"] == "migration"
|
||||||
assert kanta.ctx.source == "migration"
|
assert kanta.ctx.source == "migration"
|
||||||
|
|
||||||
@@ -90,8 +89,8 @@ def test_migration_can_omit_kanta_argument():
|
|||||||
d["x"] = 1
|
d["x"] = 1
|
||||||
|
|
||||||
state = {}
|
state = {}
|
||||||
new_ver = reg.apply(state, current_version=0, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=0, kanta=kanta)
|
||||||
assert new_ver == 1
|
assert result.version == 1
|
||||||
assert state["x"] == 1
|
assert state["x"] == 1
|
||||||
|
|
||||||
|
|
||||||
@@ -107,7 +106,7 @@ def test_version_too_new():
|
|||||||
DatabaseError,
|
DatabaseError,
|
||||||
match="Database version v2 is newer than the highest supported version v1",
|
match="Database version v2 is newer than the highest supported version v1",
|
||||||
):
|
):
|
||||||
reg.apply({}, current_version=2, kanta=kanta, silent=True)
|
reg.apply({}, current_version=2, kanta=kanta)
|
||||||
|
|
||||||
|
|
||||||
def test_version_too_old():
|
def test_version_too_old():
|
||||||
@@ -122,7 +121,7 @@ def test_version_too_old():
|
|||||||
DatabaseError,
|
DatabaseError,
|
||||||
match="Database version v1 is older than the minimum supported version v2",
|
match="Database version v1 is older than the minimum supported version v2",
|
||||||
):
|
):
|
||||||
reg.apply({}, current_version=1, kanta=kanta, silent=True)
|
reg.apply({}, current_version=1, kanta=kanta)
|
||||||
|
|
||||||
|
|
||||||
def test_missing_middle_migration_is_skipped():
|
def test_missing_middle_migration_is_skipped():
|
||||||
@@ -138,8 +137,8 @@ def test_missing_middle_migration_is_skipped():
|
|||||||
d["y"] = 3
|
d["y"] = 3
|
||||||
|
|
||||||
state = {"x": 1}
|
state = {"x": 1}
|
||||||
new_ver = reg.apply(state, current_version=1, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=1, kanta=kanta)
|
||||||
assert new_ver == 3
|
assert result.version == 3
|
||||||
assert state["x"] == 1
|
assert state["x"] == 1
|
||||||
assert state["y"] == 3
|
assert state["y"] == 3
|
||||||
|
|
||||||
@@ -153,12 +152,12 @@ def test_old_migrations_deleted_current_supported():
|
|||||||
d["x"] = 3
|
d["x"] = 3
|
||||||
|
|
||||||
state = {"x": 2}
|
state = {"x": 2}
|
||||||
new_ver = reg.apply(state, current_version=2, kanta=kanta, silent=True)
|
result = reg.apply(state, current_version=2, kanta=kanta)
|
||||||
assert new_ver == 3
|
assert result.version == 3
|
||||||
assert state["x"] == 3
|
assert state["x"] == 3
|
||||||
|
|
||||||
|
|
||||||
def test_migration_log_only_when_changed(caplog):
|
def test_apply_returns_change_information():
|
||||||
reg = Migrations()
|
reg = Migrations()
|
||||||
kanta = _DummyKanta()
|
kanta = _DummyKanta()
|
||||||
|
|
||||||
@@ -177,28 +176,33 @@ def test_migration_log_only_when_changed(caplog):
|
|||||||
"""Set y."""
|
"""Set y."""
|
||||||
d["y"] = 3
|
d["y"] = 3
|
||||||
|
|
||||||
with caplog.at_level(logging.INFO, logger="kanta.migrations"):
|
result = reg.apply({}, current_version=0, kanta=kanta)
|
||||||
reg.apply({}, current_version=0, kanta=kanta)
|
assert result.version == 3
|
||||||
|
assert len(result.migrations) == 3
|
||||||
|
|
||||||
messages = [r.message for r in caplog.records if r.levelno == logging.INFO]
|
assert result.migrations[0].name == "migrate_v1"
|
||||||
assert len(messages) == 2
|
assert result.migrations[0].description == "Set x"
|
||||||
assert "migrate_v1" in messages[0]
|
assert result.migrations[0].changed is True
|
||||||
assert "Set x" in messages[0]
|
assert result.migrations[0].diff == {"$replace": {"x": 1}}
|
||||||
assert "migrate_v3" in messages[1]
|
|
||||||
assert "Set y" in messages[1]
|
assert result.migrations[1].name == "migrate_v2"
|
||||||
|
assert result.migrations[1].description == "No-op"
|
||||||
|
assert result.migrations[1].changed is False
|
||||||
|
assert result.migrations[1].diff is None
|
||||||
|
|
||||||
|
assert result.migrations[2].name == "migrate_v3"
|
||||||
|
assert result.migrations[2].description == "Set y"
|
||||||
|
assert result.migrations[2].changed is True
|
||||||
|
assert result.migrations[2].diff == {"y": 3}
|
||||||
|
|
||||||
|
|
||||||
def test_no_op_migration_produces_no_log(caplog):
|
def test_description_defaults_to_version_when_no_docstring():
|
||||||
reg = Migrations()
|
reg = Migrations()
|
||||||
kanta = _DummyKanta()
|
kanta = _DummyKanta()
|
||||||
|
|
||||||
@reg.register
|
@reg.register
|
||||||
def migrate_v1(d):
|
def migrate_v1(d):
|
||||||
"""No-op."""
|
d["x"] = 1
|
||||||
pass
|
|
||||||
|
|
||||||
with caplog.at_level(logging.INFO, logger="kanta.migrations"):
|
result = reg.apply({}, current_version=0, kanta=kanta)
|
||||||
reg.apply({}, current_version=0, kanta=kanta)
|
assert result.migrations[0].description == "v1"
|
||||||
|
|
||||||
info_messages = [r for r in caplog.records if r.levelno == logging.INFO]
|
|
||||||
assert not info_messages
|
|
||||||
|
|||||||
Reference in New Issue
Block a user