fix(consensus-db): count a decided-block write once in DB metrics (#142)

[devorun]

Summary

Fixes #142.

insert_decided_block timed and reported the entire method — including the insert_certificate call — while insert_certificate also reported its own write through update_write_metrics. Since update_write_metrics both observes write_time and increments write_count (via add_write_bytes), every decided block was counted as two writes: the certificate's write_time was observed twice and write_count incremented twice, overstating both DB write latency and write throughput.

Fix

Give the committing method sole ownership of the write metrics:

• insert_certificate now returns the number of bytes written and records no metrics itself. It runs inside the caller's write transaction and never commits on its own, so it should not be reported as an independent write.
• insert_decided_block sums block + certificate bytes and emits a single update_write_metrics call that also covers the commit (the real cost of the durable write).
• extend_certificate — the other insert_certificate caller — now records its own single write, preserving its previous behavior.

Net effect: a decided block (block + certificate committed in one transaction) is counted exactly once.

Test

Adds store_decided_block_counts_a_single_write, asserting write_count increases by exactly one across a store_decided_block call (previously two). Uses the existing test harness (tempdir, arbitrary_payload) plus a small test-only DbMetrics::write_count() accessor.

Notes

• No dependency or public-API changes: insert_certificate is a private method with two in-crate callers, both updated.
• Opened as a draft so CI can validate fmt / clippy / tests; will mark ready for review once green.

[osr21]

Read the full diff plus the surrounding store.rs at 9d7cbe38. The diagnosis matches the code on main — insert_certificate called update_write_metrics internally while insert_decided_block wrapped the whole thing in its own observation, so every decided block bumped write_count twice and observed the certificate's write_time twice. The chosen fix (make the transaction owner the sole metrics reporter, have the helper return bytes) is the right ownership model, and the doc comment on insert_certificate spelling out why it doesn't record metrics is exactly the kind of comment that prevents the bug from being reintroduced by the next caller. One inconsistency to fix, one smaller note.

1. extend_certificate stops the clock before the commit — the opposite of the principle this PR establishes. The new code reads:

let start = Instant::now();
let write_bytes = self.insert_certificate(...)?;
let write_time = start.elapsed();   // <-- clock stops here

tx.commit()?;                        // <-- durable-write cost excluded

self.update_write_metrics(write_bytes, write_time);

Meanwhile insert_decided_block (correctly, and per the PR body's own framing — "a single update_write_metrics call that also covers the commit (the real cost of the durable write)") observes start.elapsed() after tx.commit(). For redb, the commit is where the actual fsync/durability cost lives — the table insert into an open write transaction is comparatively cheap — so extend_certificate's recorded write_time will systematically exclude the dominant term. That also means the two write paths now feed the same histogram with differently-scoped measurements, which is precisely the kind of skew #142 is about. Fix is minimal: move let write_time = start.elapsed(); below tx.commit()?; (and arguably start above begin_write() to match insert_decided_block, which times from before the transaction opens). The "preserves previous behavior" note in the PR body is true — the old code inside insert_certificate also stopped before commit — but since this PR is defining the convention "the committing method records the whole durable write," extend_certificate should follow it rather than preserve the old truncated measurement.

2. Test is well-targeted; consider one cheap extension. store_decided_block_counts_a_single_write pins the regression with a count delta, which is the observable that was wrong — good. Since extend_certificate is the other path whose metrics semantics this PR touches, a sibling assertion (extend an existing certificate, assert write_count +1) would pin that path too; today it has zero metrics coverage, and it's the path that just changed from helper-recorded to caller-recorded. Same harness, ~10 lines.

Minor observations, no action needed: the #[cfg(test)] write_count() accessor is appropriately scoped (pub(crate), test-only) rather than widening the metrics API; metrics are recorded only after a successful commit on both paths, so failed transactions correctly don't count as writes; and the byte accounting (encoded block + encoded certificate) matches what actually lands in the tables.

With the extend_certificate timing moved after the commit, this is a clean, convention-setting fix for #142.

[devorun]

Thanks for the careful read — both points were spot on.

1. Fixed in 06fcbd1: extend_certificate now records write_time after tx.commit(), so it captures the durable-write (commit/fsync) cost like insert_decided_block, and both paths feed write_time with the same scope. I kept start just before the write (after the existing-certificate validation reads) rather than above begin_write(), so read latency from the validation lookup doesn't leak into write_time — insert_decided_block has no reads in its timed section, so this keeps the two comparable. Happy to hoist it above begin_write() if you'd prefer strict symmetry.

2. Added extend_certificate_counts_a_single_write in the same commit, mirroring the decided-block test to pin the extend path at +1.

[osr21]

Verified both at 06fcbd1 — the diff now shows update_write_metrics(write_bytes, start.elapsed()) after tx.commit() in extend_certificate (with a comment explaining the scope, which will keep the convention alive), and extend_certificate_counts_a_single_write pins the extend path at exactly +1. Both points fully addressed.

On your open question — keep start where you put it; don't hoist above begin_write(). Your placement is the more principled one: the existing-certificate lookup and extension-validity checks are read work, and folding them into write_time would pollute the write histogram with read latency that update_read_metrics is supposed to own. Strict symmetry with insert_decided_block isn't actually broken either, because that method's timed section contains no reads — both paths now measure "serialize + insert + commit," which is the meaningful definition of a write observation. The tiny asymmetry that remains (decided-block includes begin_write() acquisition, extend doesn't) is noise compared to the fsync cost and not worth contorting the code over. If anything, a future cleanup could move insert_decided_block's start to after begin_write() for the same reason — but that's cosmetic and out of scope here.

Nothing further from me — once CI is green and this leaves draft, it's a clean fix for #142 that also leaves the metrics ownership rule documented where the next contributor will trip over it. Nice turnaround.

[devorun]

Appreciate the thorough review — and the confirmation on the timer placement. Marking this ready for review.