Skip to content

fix(blockchain): record tick-interval sample on proposer interval-0 skip#513

Closed
MegaRedHand wants to merge 2 commits into
mainfrom
fix/tick-interval-metric-interval0-skip
Closed

fix(blockchain): record tick-interval sample on proposer interval-0 skip#513
MegaRedHand wants to merge 2 commits into
mainfrom
fix/tick-interval-metric-interval0-skip

Conversation

@MegaRedHand

Copy link
Copy Markdown
Collaborator

Problem

lean_tick_interval_duration_seconds was reporting a spurious ~1.6s tail on every proposer slot, which read as the tick loop stalling. It is a metric-accounting artifact, not real tick lag.

On a proposer slot, the block is built during interval 4 of the previous slot; building advances the store clock to the next slot's interval 0, so the real interval-0 tick is skipped by on_tick's idempotency guard. The metric measures wall-clock time between consecutive recorded ticks, and a skipped tick neither records a sample nor advances last_tick_instant, so the following interval-1 tick measured across two intervals (~1.6s) even though ticks were firing on their 0.8s cadence.

Fix

Record the tick-interval sample from the proposal path, after the publish-alignment sleep (i.e. at ~the interval-0 boundary), standing in for the skipped interval-0 tick. Per-slot samples then stay at ~one interval.

  • Clean case (build fits within its interval): interval-0 records ~0.8s. ✅
  • Overrun case (build > 0.8s, common under load): the interval-0 sample instead reflects the real build-block duration, which is the honest signal (the actor genuinely couldn't tick on time), rather than a phantom two-interval smear.

Scope: only the proposer path is touched, since that is the only source of the interval-0 skip. A genuinely delayed tick (e.g. a slow on_block import) is unaffected and still shows as real lag.

Verification

Confirmed on a single-node local devnet (0 gossip imports isolate the proposer path): before the fix, tick samples >1.2s were 1:1 with block builds and pinned at ~1.6s; all skipped ticks were at interval 0 (BlockPublication). With the fix the skipped interval-0 slot is accounted for.

On a proposer slot the block is built during interval 4 of the previous
slot, which advances the store clock to the next slot's interval 0. The
real interval-0 tick is then skipped by on_tick's idempotency guard.

Because lean_tick_interval_duration_seconds measures wall-clock time
between consecutive *recorded* ticks, and a skipped tick neither records
a sample nor advances last_tick_instant, the following interval-1 tick
measured across two intervals and reported a false ~1.6s spike, even
though ticks were firing on their 0.8s cadence.

Record the tick-interval sample from the proposal path, after the
publish-alignment sleep (i.e. at ~the interval-0 boundary), standing in
for the skipped interval-0 tick so samples stay at ~one interval.
@github-actions

Copy link
Copy Markdown

🤖 Codex Code Review

  1. crates/blockchain/src/lib.rs:832-852 can corrupt the tick-interval metric on proposal overruns. The new sample/update is correct only when the proposer actually sleeps to the slot boundary, but it now runs unconditionally. If block building overruns into interval 1+, handle_tick immediately schedules a catch-up tick (crates/blockchain/src/lib.rs:1214-1220), and that next on_tick will observe a near-zero duration because last_tick_instant was just reset at line 852. That both introduces false low samples and hides the real “missed cadence” overrun. The fix is to gate the new observe_tick_interval_duration / last_tick_instant update on the “we actually aligned via sleep” case, or otherwise synthesize the interval-0 boundary instead of using Instant::now() after an overrun.

I didn’t see consensus, fork-choice, attestation, SSZ, or security-impacting changes in this diff beyond that metrics-path bug.


Automated review by OpenAI Codex · gpt-5.4 · custom prompt

@github-actions

Copy link
Copy Markdown

🤖 Kimi Code Review

The fix addresses a legitimate metrics drift issue caused by the interaction between block proposal timing and the idempotency guard in on_tick. The logic is sound: manually recording the interval prevents the next tick from measuring a false 2-interval gap.

Concerns:

  1. Concurrency safety (Line 848-850): If self.last_tick_instant is accessed by both the proposal task (this code) and the ticker task (which calls on_tick), this constitutes a data race unless last_tick_instant uses interior mutability (e.g., Mutex<Option<Instant>>) or the server ensures mutual exclusion via actor/message-passing semantics.

    • Verify: Ensure BlockChainServer uses &mut self for this method and that the ticker cannot concurrently access the field, or confirm last_tick_instant is properly synchronized (e.g., AtomicCell<Instant> or mutex-protected).
  2. Idempotency window: The comment assumes on_tick checks the store clock before attempting to update last_tick_instant. If on_tick checks the clock, determines it should run, but then yields before updating last_tick_instant, this code could interleave and cause duplicate recordings or inconsistent state.

    • Verify: Ensure on_tick performs its idempotency check and state update atomically with respect to this proposal path.

Minor:

  • Line 849: Consider using std::mem::replace or take() if you want to ensure the field is never observed in an inconsistent state during the metric observation, though this is likely unnecessary if the method has &mut self access.

Consensus note: Accurate timing metrics are critical for detecting network partitioning and clock skew. This fix prevents false positives in the lean_tick_interval_duration_seconds histogram that could trigger unnecessary alerts during healthy proposal duties.

Verdict: Correct fix, but verify the concurrency model for last_tick_instant access.


Automated review by Kimi (Moonshot AI) · kimi-k2.5 · custom prompt

@greptile-apps

greptile-apps Bot commented Jul 14, 2026

Copy link
Copy Markdown
Contributor

Greptile Summary

This PR adjusts tick metric accounting in the proposer path.

  • Records a tick-interval sample after the slot-boundary alignment sleep.
  • Updates last_tick_instant from the proposer path when interval 0 is skipped.
  • Leaves the normal on_tick metric path unchanged.

Confidence Score: 5/5

This looks safe to merge.

  • No blocking issues found in the changed code.

Important Files Changed

Filename Overview
crates/blockchain/src/lib.rs Adds proposer-path tick interval metric recording after publish alignment to account for the skipped interval-0 tick.

Reviews (1): Last reviewed commit: "fix(blockchain): record tick-interval sa..." | Re-trigger Greptile

MegaRedHand added a commit that referenced this pull request Jul 14, 2026
… don't inflate it (#514)

Alternative to #513 (same bug, different approach).

## Problem

`lean_tick_interval_duration_seconds` reported a spurious ~1.6s tail on
every proposer slot. It measures wall-clock time between consecutive
*recorded* ticks, recorded inside `on_tick` **after** the idempotency
guard. A guard-skipped tick records no sample and doesn't advance
`last_tick_instant`. On a proposer slot the block is built during
interval 4 of the previous slot, which advances the store clock to the
next slot's **interval 0**, so the real interval-0 tick is skipped — and
the following **interval-1** tick then measured across two intervals
(~1.6s) even though ticks were firing on their 800ms cadence.

## Approach

Move the sample to `handle_tick`, the scheduler-level handler that runs
for **every** tick (including guard-skipped ones). One sample per tick
regardless of whether `on_tick` drops the duty, so a skipped interval no
longer inflates the next sample.

Versus #513 (which records from the proposer path after the
publish-alignment sleep): this needs **no proposer special-casing** and
covers any skip uniformly. It matches how Zeam records the same metric
(at the clock layer, decoupled from duty execution).

**Tradeoff:** wall-clock-drift duplicate ticks (which the guard also
swallows) are now sampled too, adding occasional sub-interval samples.
Harmless for a metric meant to surface *late* ticks; noted in the
comment.

## Verification

Confirmed on a single-node local devnet (0 gossip imports isolate the
proposer path). Behavior is equivalent to #513: the skipped interval-0
tick is now sampled (sample count rises to ~5/slot), no pinned ~1.6s
artifact remains, and the large samples track the real (variable)
block-build duration rather than a fixed two-interval value. Total
recorded time is unchanged (`_sum` matches #513's run).

Co-authored-by: Pablo Deymonnaz <pdeymon@fi.uba.ar>
@MegaRedHand

Copy link
Copy Markdown
Collaborator Author

Superseded by #514

@MegaRedHand MegaRedHand deleted the fix/tick-interval-metric-interval0-skip branch July 14, 2026 20:47
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.

1 participant