fix(audit): hash created_at at the precision Postgres stores#2638
fix(audit): hash created_at at the precision Postgres stores#2638shani-singh1 wants to merge 2 commits into
Conversation
`log_inner` stamped entries with `Utc::now()` (nanoseconds) and hashed the value via `to_rfc3339()`, whose sub-second digit count follows the value. `audit_log.created_at` is `TIMESTAMPTZ` — microsecond resolution — so `verify_chain` recomputed the digest over a different byte string than the one that was written and returned `HashMismatch` on untampered data. Every chain backed by a real database failed verification at its first entry, which also made a genuinely forged row indistinguishable from the baseline failure. Reduce `created_at` to the stored precision before hashing, so the in-memory entry and the row are byte-identical. `log_inner` is the only place that assigns it — every caller goes through `NewAuditEntry`, which carries no timestamp — so this is a single choke point. Tests: three Postgres-free tests in `hash.rs` pinning the invariant, the trap that caused it, and the round trip; plus a non-ignored `service.rs` test that the write path's timestamp carries no sub-microsecond digits, so a regression is caught by `just test-unit` rather than only by the `#[ignore]` chain tests. Rows written before this stay unverifiable — they always were — so no migration is needed, but an operator relying on an existing chain has to re-anchor. Fixes block#2637 Signed-off-by: Shani Singh <teamdeveloperworld@gmail.com>
09d3868 to
ebfcb93
Compare
|
P0 triage — merge candidate. 🐝 Reviewed the diff. The root cause is real and the fix is correct:
One thing worth confirming before merge: that every write path routes |
Truncating at the write path fixes the live break, but leaves the invariant as a convention: a future write path that stamps `created_at` without `to_storage_precision` reintroduces the write/read preimage split. Normalize at the single point that consumes the value instead, so the enforcement is structural. Truncation is idempotent and the write path already truncates, so no digest changes — verified by writing a chain with the previous commit and validating those same rows under this one. The `assert_ne!` test that pinned the trap moved down a level: it now asserts on the RFC-3339 preimage (`.123456789` vs `.123456`), which is the property that actually causes the split, and a new test asserts `compute_hash` yields the same digest either way. Signed-off-by: Shani Singh <teamdeveloperworld@gmail.com>
|
Both points addressed — the second one by taking your suggestion. Every write path. Confirmed: there is exactly one. The enforcement point. You were right that convention isn't enough, so I did it: 08bcce9 moves the normalization into hasher.update(
to_storage_precision(entry.created_at)
.to_rfc3339()
.as_bytes(),
);A future write path that forgets to truncate now can't split the preimage — write-time hashes Digest stability, verified rather than argued. Since the write path already truncates, normalizing again should be a no-op on real chains — but "should be" isn't good enough for a hash function, so I checked it against Postgres: wrote a 3-entry chain with the previous commit, then verified those same rows with this one via a throwaway integration test. So this commit is digest-compatible with the one before it — no re-anchoring needed on top of what the first commit already required. Test restructure.
Re-ran everything after the change: 13 unit tests pass without Postgres, 6/6 chain tests pass against Postgres 17, clippy |
Fixes #2637 — full analysis and reproduction there.
Problem
Audit entries are stamped and hashed with
Utc::now()(nanoseconds), then stored in aTIMESTAMPTZcolumn (microseconds).compute_hashcoverscreated_at.to_rfc3339(), and chrono emits 0/3/6/9 fractional digits depending on the value — so the digest written atservice.rs:103is computed over…T12:00:00.123456789+00:00whileverify_chainrecomputes over the…T12:00:00.123456+00:00that Postgres hands back.Every hash chain backed by a real database therefore fails verification at its first entry, on untampered data. That is not just a broken feature — it means a genuinely forged row is indistinguishable from the permanent baseline failure, so
HashMismatchcarries no signal.It is invisible in CI because all six chain tests are
#[ignore = "requires Postgres"], and the in-processhash.rstests use a fixture timestamp of2026-01-01T00:00:00Z— zero sub-seconds, the one value where the bug cannot appear.Solution
Reduce
created_atto the stored precision before hashing, so the in-memory entry and the row are byte-identical:log_inneris the only place that assignscreated_at— every caller goes throughNewAuditEntry, which carries no timestamp — so this is a single choke point. It is wrapped in alog_timestamp()helper purely so the invariant is assertable without a database.I chose truncation at the write path over the alternative (hashing a precision-independent encoding such as
timestamp_micros().to_be_bytes()). Both fix the mismatch, but truncating keeps the existing hash preimage format and gives the stronger invariant: theAuditEntryreturned fromlog()is now exactly what a later read returns.Truncation matches what actually happens on the wire — sqlx encodes
DateTime<Utc>as microseconds since the Postgres epoch, truncating — so the value hashed is the value stored.Validation
Toolchain note: built on Windows with the
x86_64-pc-windows-gnutoolchain (no MSVC linker locally).Before, against Postgres 17 with
migrations/*applied:with
HashMismatch { seq: 2 }/HashMismatch { seq: 1 }on untampered chains.After, same database:
verify_detects_tampering_within_a_communityis the one to look at: it assertsHashMismatchlands on the tampered entry'sseq. It was failing because verification already blew up on an earlier untampered row — so the assertion proving tamper detection works had never actually been exercised. It passes now.Also:
cargo test -p buzz-audit --lib(no Postgres) — 12 passed, 0 failed.cargo clippy -p buzz-audit --all-targets -- -D warnings— clean.cargo fmt -p buzz-audit -- --check— clean.New tests
Three in
hash.rs, none needing Postgres:storage_precision_drops_sub_microsecond_digits— the helper's contract, and that it is idempotent so a re-read value is unchanged.nanosecond_timestamps_cannot_survive_a_database_round_trip— asserts the digests differ. This is the trap itself, written down so the next person changing the hash preimage sees why the precision reduction is load-bearing.storage_precision_timestamps_survive_a_database_round_trip— the invariant the write path must hold.Plus
log_timestamp_carries_no_sub_microsecond_digitsinservice.rs, deliberately not#[ignore]d, so a regression on the write path is caught byjust test-unitinstead of only by Postgres-gated tests that normally never run.Compatibility
Rows written before this stay unverifiable — they always were — so there is no migration. An operator relying on an existing chain has to re-anchor.
Relationship to #2620
#2620 proposes a shared
verify_entrieswalk (anchoring, seq contiguity, tail-truncation detection) plus abuzz-admin audit verifycommand. Its Postgres-free unit tests build entries in memory and would pass regardless, but its#[ignore]Postgres tests and the operator command itself would fail on every real chain until this lands. Worth taking this first so that work has a verifiable baseline — the two changes don't overlap in code.