Skip to content

fix(spammer): timestamp catch-up blocks individually - #229

Open
mehmetkr-31 wants to merge 1 commit into
circlefin:mainfrom
mehmetkr-31:fix/catch-up-scan-per-block-timestamp
Open

fix(spammer): timestamp catch-up blocks individually#229
mehmetkr-31 wants to merge 1 commit into
circlefin:mainfrom
mehmetkr-31:fix/catch-up-scan-per-block-timestamp

Conversation

@mehmetkr-31

Copy link
Copy Markdown

Summary

catch_up_scan propagated the received_at of the notification that triggered the scan to every block it fetched, so all N blocks recovered after a subscriber reconnect shared a single observation time.

Fixes #128.

Why it matters

BlockEvent::received_at is what LatencyTracker uses as the finalization observation time for every transaction in the block (tracker.rs, scan_and_record_block(&evt.block, evt.received_at)). So a reconnect gap covering N blocks did not just flatten the latency distribution — it skewed it:

  • all N blocks report identical latency, anchored at the reconnect moment;
  • blocks fetched late in the scan are credited with an observation time from before they were actually fetched, understating their latency.

Since the whole point of the spammer's latency pipeline is to measure when blocks were observed, a gap scan silently degrades exactly the data the tool exists to produce.

Change

Capture timestamp_now() per block inside the scan loop, and drop the now-unused received_at parameter from catch_up_scan. This is the fix suggested in the issue.

The notification path is unchanged and still uses the header-arrival time from HeaderNotification::received_at — that timestamp is genuinely the arrival moment for those blocks, so it remains the more accurate source there.

The pre-existing TODO: should we use the blocks' timestamps? is left in place: switching to on-chain block timestamps is a separate question about what the metric should measure, and this PR only removes the collapsing behaviour.

Testing

cargo fmt --all --check, cargo clippy -p spammer --all-targets --all-features -- -D warnings, and cargo test -p spammer all pass locally.

I did not add a unit test, and wanted to flag the reasoning rather than leave it unexplained: catch_up_scan takes a concrete &mut WsClient, so exercising it needs a mock WebSocket server, which is a larger change than this fix and does not match the existing test style in crates/spammer (unit tests over pure functions). Asserting "timestamps differ" would also be flaky, since timestamp_now() has millisecond resolution and a fast scan can legitimately produce equal values.

Happy to add a test if you would like one — introducing a small trait seam over the block-fetch call would make the loop testable without a live client. Let me know which direction you prefer.

`catch_up_scan` propagated the `received_at` of the notification that
triggered the scan to every block it fetched, so all N blocks recovered
after a subscriber reconnect shared one observation time.

The latency tracker uses `BlockEvent::received_at` as the finalization
observation time for every transaction in the block, so a gap covering N
blocks reported N identical latencies anchored at the reconnect moment.
That both flattens the latency distribution and skews it: blocks fetched
late in the scan are credited with an observation time from before they
were fetched.

Capture `timestamp_now()` per block inside the scan loop instead. The
notification path is unchanged and still uses the header-arrival time.

Fixes circlefin#128

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

@osr21 osr21 left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Read the full diff and the surrounding block_stream.rs at cfe96be0 against #128. The fix is exactly the issue's suggested shape, and the details are right in ways that are easy to get wrong:

  • Timestamp placement is correct. timestamp_now() is captured after fetch_block returns, not before the fetch — so retry/backoff time inside fetch_block is included in the observation moment. That's the truthful semantics: the block genuinely wasn't observed until the fetch succeeded.
  • Dropping the received_at parameter (not just ignoring it) is the right call — it makes the "one notification timestamp fans out to N blocks" mistake unrepresentable at the call site rather than merely avoided.
  • The BlockEvent::received_at doc update matters as much as the code change — the field now has two provenance modes (header arrival vs. fetch time), and documenting that at the struct is what keeps downstream consumers honest about it.
  • Leaving the on-chain-timestamp TODO in place is correct scoping. Switching to block timestamps changes what the metric measures (network-wide propagation vs. this-observer latency); this PR only fixes the collapsing bug within the current definition.

One interpretation note worth recording for whoever consumes this data (not a change request): with this fix, catch-up blocks report honest observation latency — but that is now recovery latency, not propagation latency. The Nth block in a gap scan carries the serial fetch cost of the N−1 blocks before it, so a reconnect after a long gap will produce a run of high-latency samples that reflect the scan, not the network. That's strictly better than the old behavior (which fabricated identically-low latencies anchored before the blocks were even fetched), but the two failure directions are opposite: before the fix gap scans flattened and understated; after it they legitimately inflate. If the latency pipeline ever needs to separate the two populations, a catch_up: bool on BlockEvent (or an event-source tag) would let the tracker segregate or drop scan samples — cheap to add later and only if the data shows it matters; the TODO about block timestamps is the other road to the same destination.

On the missing unit test — agree with the reasoning, and the flakiness caution is half right. "Timestamps differ" would indeed be flaky at millisecond resolution, but the property actually worth pinning is monotonic non-decrease within a scan plus each timestamp ≥ its fetch completion, which is not flaky. That said, it still requires the trait seam over the block-fetch call to exercise, and bolting a mock WebSocket layer onto a crate whose test style is pure-function units is a bigger change than this two-line fix warrants. Deferring is the right call; if the seam ever gets introduced for other reasons, the monotonicity assertion is the test to write.

Approving — minimal diff, correct semantics, honest about its own limits.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

chore(refactor): catch-up scan uses stale received_at timestamp

2 participants