The audit log in this tool records every write attempt against the upstream case-management system. Every accepted write, every rejected write, every guard refusal, every override redemption. It is the trail an attorney's compliance review walks back from a question like "did the system actually do what the attorney asked, and when." The log is supposed to be append-only and durable. Lose an entry and the trail breaks.

A probe of the rotation path found that under concurrent load, the trail was breaking. Ten processes writing 50 entries each — 500 entries expected — landed somewhere between 374 and 499 in the log. Loss per run ranged from 1 to 126. The system the audit log existed to monitor was losing the very entries the audit was trying to record.

The two bugs

The first bug was the simpler one. The rotation function read the audit.log file, gzipped it to audit.log.1.gz, then wrote an empty string to audit.log to truncate it. No lock. No coordination. While that sequence ran, any concurrent appendAudit() in another process could open audit.log with O_APPEND, write a line, and close — but if the close happened after the rotation's truncate, the line's bytes were already in a file that no longer existed.

O_APPEND on POSIX is atomic for the write itself, but it's atomic against the file as it currently exists. If the file gets truncated to zero, the write goes into the file's new state and the bytes are still there — but if the truncation happens after the write, the bytes are gone. The exact sequence depends on kernel scheduling and is not reproducible by single-process tests.

The second bug was the rename loop in the rotation. The archives were named audit.log.1.gz through audit.log.5.gz (with KEEP=5). Each rotation did a shift loop: rename .5 → drop, .4 → .5, .3 → .4, .2 → .3, .1 → .2, then gzip current to .1.gz. Five renames per rotation. The shift loop is correct in isolation — iterates from the highest number down so the next slot is always free.

The shift loop is not correct when two rotations race. Two processes both decide they need to rotate at roughly the same time. Process A acquires no lock and starts shifting. Process B acquires no lock and starts shifting. A's .3 → .4 rename runs at the same time as B's .4 → .5 rename. The filesystem semantics of overlapping renames produce gaps: .4.gz ends up missing, .5.gz ends up with the content from .3.gz overwritten, and the audit entries that were in the original .4.gz are gone forever.

The probe captured this state: after running the test, the archive directory contained .1.gz, .2.gz, .3.gz, .5.gz, .7.gz, .8.gz, ... with conspicuous gaps at .4 and .6. Each gap was an audit-batch that had been there and was now nowhere.

Fix part one: a file lock

The first fix is the obvious one: hold a lock around the read-rotate-write sequence so that no other process can append to audit.log while the rotation is in flight, and so two rotations can't shift each other's files into oblivion.

This codebase already has a battle-tested lock pattern from earlier fixes (the upload-binding storage layer uses one): O_EXCL acquire, PID-liveness primary stale check, mtime fallback for inconclusive PID checks, negative-age guard on the mtime check to handle clock skew. Reusing the same pattern keeps the lock semantics consistent across modules and avoids re-debugging an unfamiliar lock design.

The lock timeout matters here in a way it doesn't for the binding lock. For binding writes, a 3-second timeout is fine — if the lock can't be acquired, the operation fails and the attorney gets an error. For the audit log, the calling operation is "we just did a thing, record that we did it." Returning an error to the caller after the action has already happened is unhelpful. The trade-off is between blocking the caller (audit becomes a performance bottleneck) and silently dropping under contention (audit becomes unreliable). For legal-grade audit the right answer is to wait longer. The new timeout is 30 seconds.

Fix part two: get rid of the rename loop

The lock alone reduced loss from "40 to 126 per run" to "0 to 2 per run." A massive improvement, but the remaining few-entry losses suggested the rename loop was still flaky even when serialized — likely because each individual rename in the loop has its own swallow-the-error try/catch, so a transient EBUSY or AGAIN on macOS could leave the chain partially shifted without anyone noticing.

The better fix is to remove the loop entirely. Archives are now named with an ISO-8601 timestamp:

audit.log.2026-05-24T11-30-00-123Z.gz

The timestamp is precise to the millisecond. The colon characters are replaced with hyphens (Windows path safety). On the rare same-millisecond collision under extreme concurrency, a process-PID suffix is appended for uniqueness.

Archive cleanup is now trivial: list the directory, filter to audit.log.*.gz, sort alphabetically (which sorts chronologically because ISO-8601 is lexically ordered the same as time), drop the oldest beyond KEEP. No renames. No shift loop. No way to produce a gap or overwrite an archive. The archive once written is immutable.

The trade-off: the filename format changes from numbered to timestamped. Legacy audit.log.1.gz files from pre-4.5.94 installs continue to be read by /changelog and aai-undo (which globs audit.log.*.gz) and will naturally age out as new rotations land the timestamp form.

The verification

The same probe that produced the failure on the old code: 10 concurrent processes, each writing 50 audit entries, with rotation threshold set low (MAX_BYTES=2000) so rotation fires roughly every 67 entries — about 7 rotations per run. 500 entries expected.

Pre-fix: 374 to 499 entries land. 1 to 126 lost per run. The "26%-lost" runs are the ones where two rotations raced and produced overwrites.

Post-fix: 498 to 500 entries land. 0 to 2 lost per run. Four of five runs lose zero. The remaining 0-to-2-lost is at the lock-timeout boundary under extreme contention — a separate trade-off about whether to block the calling operation when audit-log contention is so high it exceeds 30 seconds.

What I learned about probing rotation

The original code looked correct when read top-to-bottom. The lock-free rotation looks naive in hindsight, but the rename loop looks careful — it iterates in the right direction, has individual try/catch around each operation, handles Windows rename-over-existing-file. The bug pattern was specifically a race between processes, and races by their nature don't show up in single-process testing.

The probe that caught it was multi-process: spawn 10 child processes that each call appendAudit 50 times. Within a single process, the JavaScript event loop serializes everything, so concurrency bugs hide. Between processes, the kernel scheduler interleaves freely, and any unsynchronized state shows up immediately as nondeterminism in the test output. Five runs of the same probe gave five different loss counts, which was the signal that this was a race rather than a deterministic bug.

The general lesson for testing append-and-rotate logs: every probe should use spawned child processes, not Promise.all within a single process. Same-process concurrency doesn't exercise the kernel's filesystem-coordination primitives. Multi-process concurrency does. Audit logs are exactly the surface where the difference matters.

The version on the install URL is 4.5.94.