From f4e0c66907675f86606b0469a0bbe251d1a2096a Mon Sep 17 00:00:00 2001 From: Leo Vasanko Date: Thu, 6 Aug 2026 23:06:24 +0000 Subject: [PATCH] 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