Skip to content

security: audit.log_event is read-then-append non-atomic — concurrent writers fork the hash chain and break verify_chain forever #262

Description

@philluiz2323

Problem

audit.log_event (src/vouch/audit.py:67-97, post-#253) computes the chain by reading the existing log, then appending a new line:

def log_event(kb_dir: Path, *, event, actor, ...) -> AuditEvent:
    prev_hash = _last_hash(kb_dir)            # step 1: read every line, return last hash
    ev = AuditEvent(..., prev_hash=prev_hash)
    ev.hash = _compute_hash(prev_hash, _event_payload_for_hash(ev))   # step 2: derive
    with _audit_path(kb_dir).open("a", encoding="utf-8") as f:        # step 3: append
        f.write(line + "\n")
        f.flush()
        os.fsync(f.fileno())
    return ev

The three steps are not atomic. There is no fcntl.flock / msvcrt.locking / advisory lock anywhere in the function. Two processes (or two threads) calling log_event concurrently both observe the same prev_hash, each compute their own hash from it, and each append. The resulting log:

…
{event H_n, hash: H_n}
{event A, prev_hash: H_n, hash: H_a}   ← process A appended
{event B, prev_hash: H_n, hash: H_b}   ← process B appended; should have prev_hash = H_a
…

verify_chain (src/vouch/audit.py:110-134) walks the log linearly and fails at event B:

if raw["prev_hash"] != prev_hash:
    return AuditChainStatus(False, line_no, "previous hash mismatch")

So the first time two writes interleave, the chain breaks. Every subsequent event keeps chaining forward correctly from H_b, but the entry containing event B is forever flagged "previous hash mismatch" — the tamper-evidence guarantee #253 was added to provide is gone for any KB with >1 concurrent writer.

This is reachable through ordinary usage, not adversarial input:

  • A long-running vouch serve (MCP / JSONL / HTTP transport) handling concurrent agents.
  • vouch serve running alongside CLI commands (vouch supersede, vouch approve, vouch index, vouch sync-apply) on the same KB.
  • Two CLI invocations from a script (vouch approve a & vouch approve b).
  • A scheduled vouch expire (Feat/vouch expire stale proposals #136) running while vouch sync-apply writes its own audit events.

Reproducer sketch (live on upstream/test @ 2eec325):

import multiprocessing as mp
from vouch import audit
from vouch.storage import KBStore

def _writer(kb_dir, actor):
    for i in range(50):
        audit.log_event(kb_dir, event="claim.create", actor=actor,
                        object_ids=[f"{actor}-{i}"])

store = KBStore.init(tmp)
procs = [mp.Process(target=_writer, args=(store.kb_dir, f"agent-{i}"))
         for i in range(4)]
for p in procs: p.start()
for p in procs: p.join()

status = audit.verify_chain(store.kb_dir)
assert status.ok, status.reason  # FAILS with "previous hash mismatch"

Single-writer KBs are safe today (the MCP/JSONL/HTTP server is one process, and most CLI workflows run sequentially), so the chain bug stays latent until concurrency shows up. The moment it does — and the README's review-gated-by-PR story explicitly invites multi-agent / CI workflows in the same .vouch/ — the integrity claim collapses without warning.

The audit log stays correct as data under the race (every event is still well-formed, links to its actor, carries its object_ids) but stops being verifiable as a chain. verify_chain.ok becomes False and no longer differentiates "someone tampered with the log" from "two honest writers raced".

Why this matters

Suggested fix

Hold an exclusive advisory lock on the audit log for the read+derive+write sequence, with a cross-platform helper (vouch ships on Linux / macOS / Windows).

  1. Lock the critical section in log_event. Open the audit log in "a+" mode once, acquire an exclusive lock (fcntl.flock(fd, LOCK_EX) on POSIX, msvcrt.locking(fd, LK_LOCK, …) on Windows), read the tail to recover prev_hash, compute the new hash, write + flush + fsync, release. Wrap the platform branching in an _audit_lock(fd) context manager in src/vouch/audit.py so it's one place.
  2. Tail-read instead of full-log scan inside the lock. _last_hash currently iterates every line — O(N) per write, and the lock is held for that long. Seek to end - 4KB, read backwards to the last newline, parse one entry. Falls back to GENESIS_HASH for an empty / unparseable tail. Materially helps multi-writer throughput.
  3. Regression tests (tests/test_audit.py):
    • Spawn N child processes (multiprocessing, not threads — the GIL hides the file race) that each call audit.log_event K times on a shared KB; assert audit.verify_chain(kb_dir).ok is True and the total event count is N×K.
    • Same test must pass on Windows (the lock helper must not depend on POSIX-specific behaviour).
    • Lock-release-on-exception test: a writer raises mid-event — the lock is released, the next writer succeeds with a valid prev_hash.
  4. (Adjacent) Legacy log migration. Out of scope for this issue but worth flagging: verify_chain currently rejects every pre-[codex] Hash-chain audit log events #253 event with "legacy event is not hash-chained", so any KB carrying audit history from before the hash-chain feature shipped will report failure forever. A vouch migrate step that re-anchors the chain from the last legacy line forward would close that separately.

No on-disk-layout, schema, or method-surface change. Existing single-writer KBs are unaffected (the lock is uncontended); existing multi-writer KBs that have already forked the chain stay broken on read (the past is the past), but every future write is correct.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions