fix: skip ticks that don't advance past the store's interval counter

[MegaRedHand]

Motivation

A 200-slot local devnet surfaced a single ERROR Failed to build block ... target slot 81 is in the past (current is 81) on the proposing node at slot 81. Investigation traced it to a clock-domain mismatch, not the block-building path.

Root cause

on_tick derives slot/interval from the wall clock (unix_now_ms, SystemTime), but the tick cadence is driven by the monotonic clock (tokio::sleep). When the wall clock drifts behind the monotonic clock, a tick scheduled for the next interval boundary fires while the wall clock still reads the previous interval, so on_tick re-runs that interval's duties.

For a proposer at interval 0 this re-enters propose_block for a slot the state has already advanced through, and the state transition rejects it with StateSlotIsNewer. The block itself was built, published, and imported correctly the first time, so impact was limited to a noisy error log (no double block, no fork), but the re-run is incorrect.

This is a known behavior of the Docker Desktop macOS VM, whose CLOCK_REALTIME runs slow and is periodically corrected, independently of CLOCK_MONOTONIC:

• https://www.docker.com/blog/addressing-time-drift-in-docker-desktop-for-mac/
• Time drift in Moby VM and containers caused by system sleep docker/for-mac#17

Fix

Guard on_tick with the store's existing monotonic interval counter (store.time(), which only moves forward in store::on_tick). If a tick does not advance past it, the interval's duties already ran, so skip. The genesis bootstrap (store.time() == 0) is exempt, since interval 0 has not run yet.

No new state is tracked — the guard reuses store.time(). This is the inverse-safe complement to the forward-only logic already in store::on_tick.

Testing

• cargo build, cargo clippy -D warnings, cargo fmt pass.
• Not separately covered by a unit test (constructing the actor + Context has no existing harness); the guard is a pure comparison over store.time().

[github-actions]

🤖 Codex Code Review

Findings

No correctness, security, or performance issues stood out in this patch.

The new guard at crates/blockchain/src/lib.rs:195 is consistent with the underlying store semantics in crates/blockchain/src/store.rs:195: store-side tick processing only performs work while store.time() < time, so returning early when tick_interval <= store_time suppresses duplicate actor-side duties without blocking needed catch-up.

Residual risk

• There does not appear to be actor-level regression coverage for the wall-clock/monotonic drift case or the immediate re-tick path in crates/blockchain/src/lib.rs:719. The visible tests still exercise store::on_tick directly in crates/blockchain/tests/forkchoice_spectests.rs:114 and crates/blockchain/tests/signature_spectests.rs:53, so this scheduler-specific fix is not obviously covered.

I could not run cargo test in this environment: the workspace needs the lean-multisig git dependency, and network access is restricted.

---

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

[github-actions]

🤖 Claude Code Review

Here is my review of PR #424:

---

PR #424: fix: skip ticks that don't advance past the store's interval counter

Author: Tomás Grüner | Files changed: 1 | +21 / -1

---

Overview

This PR adds an idempotency guard at the top of BlockChainServer::on_tick to prevent re-running validator duties when the wall clock lags behind the monotonic tick scheduler. The root cause — Docker Desktop macOS VMs correcting CLOCK_REALTIME independently of CLOCK_MONOTONIC — is well-documented and the fix is minimal.

---

Correctness Analysis

Guard condition (lib.rs:198):

if store_time > 0 && tick_interval <= store_time {

After store::on_tick runs for a tick at interval N, it sets store.time() == N. So:

• Normal forward tick (tick_interval = N+1, store_time = N): N+1 <= N is false → proceeds. ✓
• Duplicate/stale tick (tick_interval = N, store_time = N): N <= N is true → skipped. ✓
• Wall clock backward drift (tick_interval < N, store_time = N): skipped. ✓ (without this guard, the duty-dispatch branches keyed on interval would re-run using the stale wall-clock values)

Genesis exception (store_time > 0):
Correct. At startup, store.time() == 0 and tick_interval for the first tick is also 0. Without the exception, 0 <= 0 would skip the very first interval. After the first store::on_tick processes, store.time() >= 1, so any subsequent tick_interval == 0 ticks would then be guarded normally.

Interaction with get_proposal_head / nested store::on_tick calls:
The inner store::on_tick call in get_proposal_head (called from propose_block, which fires after the outer store::on_tick has already advanced store.time() to tick_interval) would be a no-op, so no interaction issue.

---

Minor Points

last_tick_instant update precedes the guard (lib.rs:176–180):

if let Some(prev_instant) = self.last_tick_instant {
    metrics::observe_tick_interval_duration(prev_instant.elapsed());
}
self.last_tick_instant = Some(Instant::now());
// ... guard is checked below ...

When a duplicate tick fires and is then skipped, last_tick_instant is still updated. This means the next real tick's observe_tick_interval_duration measurement captures time from the duplicate, not from the previous real tick. During a clock-drift event this will produce a slightly short metric sample. It's not a correctness issue and arguably serves as a diagnostic signal, but worth noting. Moving the last_tick_instant update to after the guard would produce cleaner interval duration metrics under drift.

Logging field style (lib.rs:200–203):

debug!(
    %slot,
    %interval,
    tick_interval,
    store_time,
    "Skipping already-processed tick"
);

slot and interval use the % Display sigil (consistent with existing code for these fields), while tick_interval and store_time do not. For plain u64 fields the output is identical, so this is cosmetic — but for consistency with the codebase's pattern of using % for identifiers-as-display-values, %tick_interval and %store_time would be more uniform.

No new unit test:
Acknowledged in the PR description as structurally difficult. The guard is a two-variable comparison and is fully verifiable by inspection, so this is acceptable. A comment noting where one would add coverage if the actor harness is ever added would be nice-to-have but not required.

---

Verdict

The fix is correct and minimal. Logic, semantics of store.time(), the genesis edge case, and the interaction with store::on_tick's forward-only loop all check out. The last_tick_instant ordering is the only thing worth a second look, but it is a metrics accuracy nit, not a consensus correctness concern.

---

Automated review by Claude (Anthropic) · sonnet · custom prompt

[greptile-apps]

Greptile Summary

Adds an idempotency guard inside BlockChainServer::on_tick to handle wall-clock/monotonic-clock drift in VMs (notably Docker Desktop on macOS), where a tick scheduled for the next interval boundary can fire while the wall clock still reads the previous interval, causing propose_block to be re-entered for a slot the state has already processed.

• The guard computes tick_interval (wall-clock interval count since genesis) and compares it against store.time() (the monotonic interval counter maintained by store::on_tick); if tick_interval <= store_time and the store has advanced past genesis, the tick's duties are skipped.
• Genesis bootstrap (store_time == 0) is deliberately exempt because store::on_tick with time = 0 does not advance the counter, so the guard would otherwise block interval 0 from ever being processed after any duplicate genesis tick.
• The tracing import is extended to include debug! for the new skip-path log line.

Confidence Score: 4/5

The guard correctly prevents duplicate block proposals on wall-clock drift; the only concern is minor metric distortion from skipped ticks, which does not affect consensus correctness.

The core fix is logically sound — comparing the wall-clock-derived interval against the monotonic store counter cleanly prevents the re-proposal path. The one gap is that last_tick_instant and observe_tick_interval_duration are updated before the guard, so a skipped tick injects a near-zero sample into the histogram and shifts the baseline for the next legitimate tick's duration measurement. This is purely an observability issue and does not affect block building, attestation, or state transitions.

The metrics update block at the top of on_tick (lines 177–180 of crates/blockchain/src/lib.rs) warrants a second look, as it runs unconditionally before the idempotency guard.

Important Files Changed

Filename	Overview
crates/blockchain/src/lib.rs	Adds an idempotency guard in on_tick that compares the wall-clock-derived interval against store.time() and skips already-processed ticks; the guard is logically correct but sits after the metrics/timer update, so skipped ticks still emit a near-zero duration sample and reset last_tick_instant.

Sequence Diagram

sequenceDiagram
    participant SC as Scheduler (monotonic)
    participant OT as on_tick (wall clock)
    participant ST as store::on_tick

    SC->>OT: tick fires (interval N boundary, monotonic)
    OT->>OT: compute tick_interval from wall clock
    OT->>OT: "read store_time = store.time()"
    alt "tick_interval > store_time OR store_time == 0"
        OT->>ST: store::on_tick(timestamp_ms)
        ST->>ST: advance store.time() to tick_interval
        OT->>OT: run duties (propose_block, attest, etc.)
    else "tick_interval <= store_time AND store_time > 0"
        OT->>OT: debug log Skipping already-processed tick
        OT-->>SC: return (early exit)
    end

Loading

Comments Outside Diff (1)

1. crates/blockchain/src/lib.rs, line 176-207 (link)

   Skipped ticks still update last_tick_instant and emit a metrics observation

   last_tick_instant is set (lines 177–180) before the idempotency guard fires, so when a duplicate tick is skipped, observe_tick_interval_duration records the near-zero elapsed time since the legitimate tick, and last_tick_instant is reset to the duplicate's timestamp. This causes two metric distortions: a spuriously short sample in the histogram and an inflated duration for the next legitimate tick (measured from the skipped tick's instant rather than the prior real one). Moving the update below the guard, or skipping it on early-return, would keep the histogram accurate.

   Prompt To Fix With AI

   This is a comment left during a code review.
   Path: crates/blockchain/src/lib.rs
   Line: 176-207
   
   Comment:
   **Skipped ticks still update `last_tick_instant` and emit a metrics observation**
   
   `last_tick_instant` is set (lines 177–180) before the idempotency guard fires, so when a duplicate tick is skipped, `observe_tick_interval_duration` records the near-zero elapsed time since the legitimate tick, and `last_tick_instant` is reset to the duplicate's timestamp. This causes two metric distortions: a spuriously short sample in the histogram and an inflated duration for the *next* legitimate tick (measured from the skipped tick's instant rather than the prior real one). Moving the update below the guard, or skipping it on early-return, would keep the histogram accurate.
   
   How can I resolve this? If you propose a fix, please make it concise.

Prompt To Fix All With AI

Fix the following 1 code review issue. Work through them one at a time, proposing concise fixes.

---

### Issue 1 of 1
crates/blockchain/src/lib.rs:176-207
**Skipped ticks still update `last_tick_instant` and emit a metrics observation**

`last_tick_instant` is set (lines 177–180) before the idempotency guard fires, so when a duplicate tick is skipped, `observe_tick_interval_duration` records the near-zero elapsed time since the legitimate tick, and `last_tick_instant` is reset to the duplicate's timestamp. This causes two metric distortions: a spuriously short sample in the histogram and an inflated duration for the *next* legitimate tick (measured from the skipped tick's instant rather than the prior real one). Moving the update below the guard, or skipping it on early-return, would keep the histogram accurate.

_{Reviews (1): Last reviewed commit: "fix: skip ticks that don't advance past ..." | Re-trigger Greptile}