diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index b17af41..17715fe 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -7,9 +7,17 @@ on: jobs: test: - runs-on: ubuntu-latest + # Windows is in the matrix because this package READS AND WRITES LEDGER FILES. + # The seal-lookup reads bytes and splits lines itself, so universal-newline + # translation no longer happens for it — a CR-only ledger parsed as one line + # and the lookup answered GENESIS, which on append would have written a second + # genesis entry into the middle of a live chain. Nothing in a Linux-only matrix + # could have shown that. A tamper-evidence tool cannot have an unmeasured OS. + runs-on: ${{ matrix.os }} strategy: + fail-fast: false matrix: + os: [ubuntu-latest, windows-latest] python-version: ["3.10", "3.11", "3.12"] steps: - uses: actions/checkout@v4 diff --git a/CHANGELOG.md b/CHANGELOG.md index 65b0c3e..d2ea840 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,69 @@ Format follows [Keep a Changelog](https://keepachangelog.com/en/1.0.0/). --- +## [0.4.0] — 2026-08-25 + +### Changed +- **Appending no longer re-reads the whole ledger.** `_get_last_seal` runs on every + `record()` and parsed every line to find the last one, so append was O(n) — the + ledger got slower purely by being used, which taxes the discipline it exists to + support. On a 3,097-entry / 3.4 MB ledger one lookup cost **50.390 ms**; it now + costs **0.048 ms** and stays flat (append median over a growing ledger: 8.17× → 0.96×). + + Not cached in memory on purpose: other processes append to the same ledger, and a + cached head that is no longer last would write a `prev_seal` that forks the chain. + The file stays the single source of truth; only how much of it is read changed. + +### Fixed +- **CR-only line endings answered GENESIS.** Reading bytes meant losing text mode's + universal-newline translation, so a ledger with `\r` endings parsed as one line and + the lookup reported an empty chain — an append would then have written a second + genesis entry into the middle of a live chain. `\r\n`, `\r` and `\n` now all read + the same. Caught by a reviewer who noted the diff was file I/O in a repo with no + Windows CI, not by the tests as first written. + +- **The CLI died on consoles that cannot print emoji.** Every verdict line starts with + 🪪 / ✅ / 🔴 / ⚪, and on a cp1252 console `print` raised `UnicodeEncodeError`. So on + Windows `am verify` on an **intact** ledger exited 1 with an empty stdout — + indistinguishable from a tamper verdict, and the 0.3.0 promise that "verdicts reach + the exit code" was false there. Worse for `record`: the entry is written *before* the + confirmation is printed, so the action was sealed and the CLI still reported failure — + a caller retrying on non-zero would record it twice. + + stdout/stderr now get `errors="replace"` — **the error handler only, not the encoding**. + Forcing UTF-8 fixed the crash and moved it one process along: the child wrote UTF-8 into + a pipe its Windows caller was decoding as cp1252, and the reader died on byte `0x81` + (the 👁 in the witness line) with `stdout` coming back `None`. Keeping the console's own + encoding means whoever reads the output can still decode it; unrepresentable glyphs + degrade to `?` and the verdict words, which are ASCII, come through intact. + A verdict that cannot be printed is a verdict that did not reach anyone. + +### Added +- **`windows-latest` in the CI matrix** (3 jobs → 6). This package reads and writes + ledger files; a Linux-only matrix could not show either defect above. It found the + emoji crash on its first run — in the CLI *and*, one round later, in the shipped + example, which prints the same glyphs without going through `_cli()` and so never + inherited the fallback. A tamper-evidence tool cannot have an unmeasured OS. +- A pytest check that runs `examples/demo_family.py` on a cp1252 console. The CI dogfood + step already covered it, but only on the Windows runner and outside the number the + test suite reports: `57/57` was a pytest denominator while CI green's denominator is + pytest + dogfood + package. +- Seal-lookup equivalence tests over 15 awkward ledgers (empty, no trailing newline, + unsealed tail, corrupt lines, a line longer than the read chunk, non-ASCII, CRLF / + CR / mixed endings, missing file), each compared against a full-parse oracle — plus a + **positive control** that runs a knowingly wrong reader through the same comparison, + so "equivalent" cannot quietly mean "measuring nothing". +- A tail-read check measured in **bytes handed out by the file handle**, not wall-clock. + Its first version counted only `read()` and so passed the old line-iterating + implementation unchanged — it measures the difference only after counting iteration too. +- Console-encoding tests driven by `PYTHONIOENCODING` rather than by the OS, so they run + on every runner instead of only the Windows one — including one that decodes the pipe + with the same non-UTF-8 codec the console declared, which is what the Windows harness + does and what the UTF-8-forcing attempt broke. A tamper verdict is checked in that + console too, so the fix cannot quietly turn every run green. + +--- + ## [0.3.0] — 2026-08-14 ### Fixed diff --git a/actmirror/__init__.py b/actmirror/__init__.py index d6115e5..7a2646e 100644 --- a/actmirror/__init__.py +++ b/actmirror/__init__.py @@ -10,4 +10,4 @@ "witness_peer", "verify_peer", "cross_witness", "family_round", "family_verify", "report", "Finding", ] -__version__ = "0.3.0" +__version__ = "0.4.0" diff --git a/actmirror/am.py b/actmirror/am.py index 6e69afd..967894a 100644 --- a/actmirror/am.py +++ b/actmirror/am.py @@ -35,7 +35,7 @@ Zero dependencies (stdlib only). Deterministic. Same DNA as measure-mirror. """ from __future__ import annotations -import hashlib, json, os, time +import hashlib, json, os, sys, time from dataclasses import dataclass @@ -70,14 +70,69 @@ def _load_entries(ledger_path: str) -> list[dict]: return out -def _get_last_seal(ledger_path: str) -> str: - entries = _load_entries(ledger_path) - for e in reversed(entries): - if "seal" in e: - return e["seal"] +def _get_last_seal(ledger_path: str, _chunk: int = 8192) -> str: + """The seal of the last sealed entry — read from the END of the file. + + This runs on EVERY append. Parsing the whole ledger to find its last line made + append O(n): on the family ledger (3,097 entries / 3.4 MB) one `record` spent + 50 ms here, and the cost grows with every entry ever written — the ledger gets + slower precisely because it is being used. + + Deliberately NOT cached in memory: this ledger is appended by other processes + (cron jobs, sibling agents), and a cached head would hand out a prev_seal that + is no longer last, forking the chain. The file stays the single source of truth; + only the amount of it we read changes. + + Semantics are unchanged, including the awkward cases: unsealed or unparseable + trailing lines are skipped (as _load_entries' {_corrupt} placeholders were), a + ledger with no sealed entry at all still answers GENESIS, and CRLF / CR / LF + endings all read the same — text mode used to normalise those for us. + """ + if not os.path.exists(ledger_path): + return "GENESIS" + with open(ledger_path, "rb") as f: + f.seek(0, os.SEEK_END) + pos = f.tell() + buf = b"" + while pos > 0: + step = min(_chunk, pos) + pos -= step + f.seek(pos) + buf = f.read(step) + buf + # Split on every line ending, not just \n. Reading bytes means universal-newline + # translation no longer happens for us: a ledger written with CR-only endings + # parsed as ONE line and the lookup answered GENESIS — which would have appended + # a second genesis entry into the middle of a live chain. Normalising first is + # safe because a raw CR or LF inside a JSON string is not valid JSON anyway. + parts = buf.replace(b"\r\n", b"\n").replace(b"\r", b"\n").split(b"\n") + # parts[0] may be the tail of a line that starts earlier in the file — + # only safe to read once we have reached the beginning. + head, complete = parts[0], parts[1:] + for line in reversed(complete): + seal = _seal_of(line) + if seal is not None: + return seal + if pos == 0: + seal = _seal_of(head) + if seal is not None: + return seal + break + buf = head return "GENESIS" +def _seal_of(raw: bytes): + """`seal` of one raw ledger line, or None if it has none / does not parse.""" + line = raw.strip() + if not line: + return None + try: + entry = json.loads(line.decode("utf-8")) + except Exception: + return None + return entry["seal"] if isinstance(entry, dict) and "seal" in entry else None + + def _seal(ledger_path: str, entry: dict, sign_key: str | None = None) -> dict: entry["prev_seal"] = _get_last_seal(ledger_path) # `seal` and `sig` are attestation fields, excluded from the content hash. @@ -392,6 +447,32 @@ def report(title: str, findings: list[Finding]) -> str: # ───────────────────────────────────────────────────────────── # CLI # ───────────────────────────────────────────────────────────── +def _printable_streams() -> None: + """Make sure a verdict can always be printed, whatever the console encoding is. + + Every verdict line starts with an emoji (🪪 ✅ 🔴 ⚪). On a console whose encoding + cannot represent them — Windows defaults to cp1252 — `print` raised + UnicodeEncodeError, so `am verify` on an INTACT ledger died with a traceback, + an empty stdout and exit 1. Indistinguishable from a tamper verdict, and the + 0.3.0 promise that "verdicts reach the exit code" was false on that platform. + + Only the error handler changes — NOT the encoding. Forcing UTF-8 here fixed the + crash and moved it one process along: the child then wrote UTF-8 bytes into a pipe + that its Windows caller was decoding with the locale encoding, and the reader died + with UnicodeDecodeError instead. Whoever reads this output already knows the + console's encoding; what they cannot survive is a codec exception. So keep the + encoding they expect and let unrepresentable glyphs degrade to `?` — the verdict + words are ASCII and come through intact either way. + + A verdict that cannot be printed is a verdict that did not reach anyone. + """ + for stream in (sys.stdout, sys.stderr): + try: + stream.reconfigure(errors="replace") + except Exception: # not a reconfigurable stream (pytest capture, pipes) — fine + pass + + def _cli() -> int: """Exit codes: 0 — command ran and any verdict was OK/WARN (or the command has no verdict); 1 — a verdict-bearing command answered negatively @@ -400,6 +481,7 @@ def _cli() -> int: ledger — the verdict was print-only. Found when a commit-binding tool's tamper demo passed its ledger-mutation case. """ + _printable_streams() import argparse p = argparse.ArgumentParser( prog="am", description="🪪 Action Mirror — agent action provenance + mutual witness") diff --git a/examples/demo_family.py b/examples/demo_family.py index ef96f40..d13635f 100644 --- a/examples/demo_family.py +++ b/examples/demo_family.py @@ -18,6 +18,13 @@ from actmirror import am +# This script prints the same emoji the CLI does, but it does not go through `_cli()`, +# so it did not inherit the console fallback that lives there — and on a cp1252 console +# it died with UnicodeEncodeError. An example is the FIRST code a new user runs; failing +# here is worse than failing in a test. Private import on purpose: this is the package's +# own example, and the helper is not part of the public API. +am._printable_streams() + D = tempfile.mkdtemp(prefix="am_demo_") ledgers = {n: os.path.join(D, f"{n}.jsonl") for n in ["seara", "jebi", "sonnet"]} diff --git a/pyproject.toml b/pyproject.toml index c4f2cdf..9dd5c42 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta" [project] name = "action-mirror" -version = "0.3.0" +version = "0.4.0" description = "Agent action provenance + mutual witness network — who did what, provably." readme = "README.md" requires-python = ">=3.10" diff --git a/tests/test_am.py b/tests/test_am.py index 09b2ed5..714191c 100644 --- a/tests/test_am.py +++ b/tests/test_am.py @@ -259,3 +259,182 @@ def test_verify_signatures_signed_and_forgery(tmp_path): rows[0]["agent"] = "mallory" open(l, "w").write("\n".join(json.dumps(r) for r in rows) + "\n") assert am.verify_signatures(l)[0].level == "FAIL" + + +# ─── H. last-seal lookup: O(1) tail read, unchanged answer ─────────────── +# +# `_get_last_seal` runs on every append. It used to parse the whole ledger to +# find its last line, so append was O(n) and a ledger got slower purely by being +# used (on a 3,097-entry family ledger one lookup cost ~50 ms). It now reads +# backwards from EOF. These tests pin the part that must NOT change — the answer — +# and the part that must — how much of the file is touched. + +def _reference_last_seal(path): + """The pre-fix implementation, kept as the oracle: parse everything, scan back.""" + import os + if not os.path.exists(path): + return "GENESIS" + entries = [] + with open(path, encoding="utf-8") as f: + for line in f: + line = line.strip() + if not line: + continue + try: + entries.append(json.loads(line)) + except json.JSONDecodeError: + entries.append({"_corrupt": line[:80]}) + for e in reversed(entries): + if isinstance(e, dict) and "seal" in e: + return e["seal"] + return "GENESIS" + + +def _awkward_ledgers(tmp_path): + """The shapes a tail reader can get wrong. Returns [(label, path)].""" + def S(h): + return json.dumps({"_type": "action", "agent": "t", "action": "a", + "prev_seal": "GENESIS", "seal": h}, ensure_ascii=False) + cases, i = [], 0 + def mk(label, text): + nonlocal i + i += 1 + p = tmp_path / f"c{i}.jsonl" + # newline="" so the bytes on disk are exactly what this test wrote — otherwise + # Windows silently rewrites every \n as \r\n and the line-ending cases below + # stop testing what they name. + p.write_text(text, encoding="utf-8", newline="") + cases.append((label, str(p))) + mk("empty", "") + mk("blank lines only", "\n\n\n") + mk("single entry", S("aa" * 32) + "\n") + mk("no trailing newline", S("bb" * 32)) + mk("no sealed entry at all", '{"ts": 1, "note": "tick"}\n' * 5) + mk("unsealed trailing lines", S("cc" * 32) + "\n" + '{"note": "no seal"}\n' * 3) + mk("corrupt last line", S("dd" * 32) + "\n{ this is not json\n") + mk("corrupt middle line", S("ee" * 32) + "\n@@@\n" + S("ff" * 32) + "\n") + mk("non-ascii payload", json.dumps({"agent": "대장님", "action": "🪞", + "seal": "11" * 32}, ensure_ascii=False) + "\n") + # one line longer than the read chunk, so the tail scan must span chunks + mk("line longer than chunk", json.dumps({"agent": "t", "action": "x" * 20000, + "seal": "22" * 32}) + '\n{"note": "tail"}\n') + mk("many unsealed lines after the last seal", + S("33" * 32) + "\n" + ('{"note": "%s"}\n' % ("y" * 300)) * 100) + # Line endings: reading bytes means universal-newline translation is ours to do. + # A CR-only ledger used to parse as ONE line and answer GENESIS — an append would + # then have written a second genesis entry into the middle of a live chain. + three = [S("55" * 32), S("66" * 32), S("77" * 32)] + mk("CRLF endings", "\r\n".join(three) + "\r\n") + mk("CR-only endings", "\r".join(three) + "\r") + mk("mixed endings", three[0] + "\r\n" + three[1] + "\r" + three[2] + "\n") + cases.append(("missing file", str(tmp_path / "does_not_exist.jsonl"))) + return cases + + +def test_last_seal_matches_full_parse(tmp_path): + """The fast tail read answers exactly what parsing the whole ledger answers.""" + cases = _awkward_ledgers(tmp_path) + assert len(cases) >= 15, "the case list itself must not silently shrink to nothing" + for label, path in cases: + assert am._get_last_seal(path) == _reference_last_seal(path), label + + +def test_last_seal_oracle_rejects_a_wrong_implementation(tmp_path): + """Positive control: the comparison above must be able to FAIL. + + A test that only ever runs the correct implementation cannot tell "equivalent" + from "not measuring anything". So run a deliberately wrong reader — one that + looks only at the final line — through the same cases and require it to be caught. + """ + def wrong(path): + import os + if not os.path.exists(path): + return "GENESIS" + lines = [x for x in open(path, encoding="utf-8").read().splitlines() if x.strip()] + if not lines: + return "GENESIS" + try: + e = json.loads(lines[-1]) + except json.JSONDecodeError: + return "GENESIS" + return e["seal"] if isinstance(e, dict) and "seal" in e else "GENESIS" + + caught = [label for label, path in _awkward_ledgers(tmp_path) + if wrong(path) != _reference_last_seal(path)] + assert caught, "the equivalence check passed a knowingly broken reader — it measures nothing" + + +class _CountingFile: + """A file handle that reports how many bytes it actually handed out. + + It has to count line iteration too, not just read(): the implementation this + test replaced walked the ledger with `for line in f`, so a counter that only + wrapped read() would have recorded zero bytes for it and passed. That is the + vacuous-pass shape this repo keeps finding — the test would have measured nothing. + """ + + def __init__(self, fh, sink): + self._fh, self._sink = fh, sink + + def _count(self, data): + if data: + self._sink.append(len(data)) + return data + + def read(self, *a, **kw): + return self._count(self._fh.read(*a, **kw)) + + def readline(self, *a, **kw): + return self._count(self._fh.readline(*a, **kw)) + + def readlines(self, *a, **kw): + out = self._fh.readlines(*a, **kw) + for line in out: + self._count(line) + return out + + def __iter__(self): + for line in self._fh: + yield self._count(line) + + def __enter__(self): + self._fh.__enter__() + return self + + def __exit__(self, *a): + return self._fh.__exit__(*a) + + def __getattr__(self, name): + return getattr(self._fh, name) + + +def test_append_reads_only_the_tail(tmp_path, monkeypatch): + """Looking up the previous seal must not read the whole ledger. + + Measured structurally (bytes the file handle handed out), not by wall-clock, + so it cannot go green on a fast machine or flake on a loaded one. + """ + l = L(tmp_path) + big = json.dumps({"agent": "t", "action": "p" * 50000, "seal": "44" * 32}) + with open(l, "w", encoding="utf-8") as f: + for _ in range(40): # ~2 MB of ledger + f.write(big + "\n") + size = (tmp_path / "l.jsonl").stat().st_size + assert size > 1_000_000 + + real_open, read_sizes = open, [] + + def counting_open(file, *a, **kw): + fh = real_open(file, *a, **kw) + return _CountingFile(fh, read_sizes) if str(file) == l else fh + + monkeypatch.setattr("builtins.open", counting_open) + try: + seal = am._get_last_seal(l) + finally: + monkeypatch.undo() + + assert seal == "44" * 32 + assert read_sizes, "nothing was read at all — the counter is not wired to the lookup" + assert sum(read_sizes) < size // 10, ( + f"read {sum(read_sizes)} of {size} bytes — the lookup is still scanning the ledger") diff --git a/tests/test_cli_exit_codes.py b/tests/test_cli_exit_codes.py index 3f4aa3b..e41ad0b 100644 --- a/tests/test_cli_exit_codes.py +++ b/tests/test_cli_exit_codes.py @@ -93,3 +93,110 @@ def test_record_still_exits_0(tmp_path): led = str(tmp_path / "l.jsonl") r = cli("--ledger", led, "record", "--agent", "a", "--action", "x") assert r.returncode == 0 and "Sealed" in r.stdout + + +# ─── the verdict has to survive the console it is printed to ──────────── +# +# Every verdict line starts with an emoji (🪪 ✅ 🔴 ⚪). On a console whose encoding +# cannot represent them, `print` raised UnicodeEncodeError — so on Windows, whose +# default is cp1252, `am verify` on an INTACT ledger died with a traceback, an empty +# stdout and exit 1. Indistinguishable from a tamper verdict. +# +# Worse for `record`: the entry is written BEFORE the confirmation is printed, so the +# action was sealed and the CLI still reported failure. A caller that retries on a +# non-zero exit records it twice. +# +# Driven by PYTHONIOENCODING rather than by the OS, so this runs everywhere — a guard +# that only fires on one runner is a guard most runs never execute. +# +# The contract these pin down: output stays in the CONSOLE's encoding, so a caller +# reads it back with the same codec it declared. Each test therefore decodes as cp1252 +# too — reading UTF-8 out of a cp1252 console would be the caller's own bug. + +def cli_in_encoding(encoding, *args, read_as=None): + """Run the CLI with a given console encoding. + + `read_as` decodes the pipe with that codec instead of the caller's default — which + is what a Windows caller does, and where forcing UTF-8 output moved the crash to: + the child wrote UTF-8 into a pipe the parent was decoding as cp1252, and the reader + thread died on byte 0x81 (the 👁 in the witness line) with stdout coming back None. + """ + env = {**_ENV, "PYTHONIOENCODING": encoding} + kw = {"encoding": read_as} if read_as else {"text": True} + return subprocess.run([sys.executable, "-m", "actmirror.am", *args], + capture_output=True, env=env, **kw) + + +def test_verify_survives_a_non_utf8_console(tmp_path): + led = str(tmp_path / "l.jsonl") + am.record(led, agent="a", action="x") + r = cli_in_encoding("cp1252", "--ledger", led, "verify", read_as="cp1252") + assert "UnicodeEncodeError" not in r.stderr, "the verdict crashed on the console encoding" + assert r.returncode == 0, f"an intact chain must not exit non-zero: {r.stderr[-300:]}" + assert "OK" in r.stdout, "the verdict text itself must survive, emoji or not" + + +def test_record_survives_a_non_utf8_console(tmp_path): + """A sealed entry that reports failure is worse than a failure: retries duplicate it.""" + led = str(tmp_path / "l.jsonl") + r = cli_in_encoding("cp1252", "--ledger", led, "record", "--agent", "a", "--action", "x", + read_as="cp1252") + assert r.returncode == 0, f"record exited {r.returncode}: {r.stderr[-300:]}" + assert "seal=" in r.stdout + assert len([x for x in open(led, encoding="utf-8") if x.strip()]) == 1 + + +def test_tamper_verdict_still_reaches_the_exit_code_in_that_console(tmp_path): + """The fix must not turn every run green — a FAIL still has to be a FAIL.""" + led = str(tmp_path / "l.jsonl") + am.record(led, agent="a", action="x") + _tamper_field(led, "agent", "mallory") + r = cli_in_encoding("cp1252", "--ledger", led, "verify", read_as="cp1252") + assert r.returncode == 1 + assert "FAIL" in r.stdout + + +def test_output_is_readable_by_a_caller_using_the_same_encoding(tmp_path): + """The bytes must stay in the console's own encoding, not silently become UTF-8. + + Reproduces the Windows harness on any platform: child console cp1252, caller + decoding cp1252. Forcing UTF-8 output made this raise UnicodeDecodeError on + byte 0x81 — the fix has to keep the encoding and only replace what it cannot map. + """ + mine, peer = str(tmp_path / "mine.jsonl"), str(tmp_path / "peer.jsonl") + am.record(peer, agent="peer", action="x") + r = cli_in_encoding("cp1252", "--ledger", mine, "witness", peer, "--name", "peer", + read_as="cp1252") # 👁 lives on this path + assert r.stdout is not None, "the caller could not decode the output at all" + assert r.returncode == 0 and "Witnessed" in r.stdout + + os.remove(peer) # peer rewrites history from scratch + am.record(peer, agent="peer", action="rewritten") + r = cli_in_encoding("cp1252", "--ledger", mine, "verify-peer", peer, "--name", "peer", + read_as="cp1252") + assert r.stdout is not None + assert r.returncode == 1 and "FAIL" in r.stdout, "the verdict must survive the round trip" + + +def test_the_shipped_example_runs_on_a_non_utf8_console(): + """CI's dogfood step, brought inside the pytest denominator. + + The console fix lived in `_cli()`, and `examples/demo_family.py` does not go through + `_cli()` — it prints the same emoji directly, so it kept dying on cp1252 while the + test suite was fully green. `57/57` was a pytest denominator; CI green's denominator + is pytest + dogfood + package, and only the first one was being reported. + + An example is the first code a new user runs. Failing there is worse than failing + in a test, and it had nothing to do with any recent change — it was always broken + on that platform, with no runner that could see it. + """ + example = os.path.join( + os.path.dirname(os.path.dirname(os.path.abspath(am.__file__))), + "examples", "demo_family.py") + if not os.path.exists(example): # installed-wheel run: examples are not shipped + import pytest + pytest.skip("examples/ not present in this layout") + r = subprocess.run([sys.executable, example], capture_output=True, + encoding="cp1252", env={**_ENV, "PYTHONIOENCODING": "cp1252"}) + assert "UnicodeEncodeError" not in (r.stderr or ""), r.stderr[-400:] + assert r.returncode == 0, f"the shipped example died: {(r.stderr or '')[-400:]}"