Skip to content

feat(beacon): time the state-writer hand-off as its own import phase - #651

Open
MegaRedHand wants to merge 6 commits into
mainfrom
feat/beacon-import-writer-wait
Open

MegaRedHand wants to merge 6 commits into
mainfrom
feat/beacon-import-writer-wait

Conversation

@MegaRedHand

@MegaRedHand MegaRedHand commented Oct 2, 2026 •

Copy link
Copy Markdown
Collaborator

Motivation

Beacon post-states are persisted by one background thread fed through a bounded queue. StateWriterHandle::send blocks while the queue is full, and Store::insert_state calls it from inside fork_choice::on_block, which the chain actor times as the stf phase. If blocks import faster than the writer persists them, the importer's wait for the writer is reported as state-transition time. This PR reports the wait as its own phase, so stf measures state-transition work only.

Measured on the import-replay benchmark (128 mainnet blocks, eth-5) with this change merged into each leg:

leg stf p50 (now exclusive) writer_wait p50 block wall p50
base (beacon-chain-integration) 581 ms ~0 777 ms
each single performance PR (#647-#650, #633) 353-618 ms ~0 (max 4 us) 551-778 ms
all five performance PRs merged 202 ms 326 ms 559 ms

With all five merged, blocks import faster than the writer persists their states, so the queue fills and the importer waits about 326 ms per block. Without this phase that wait was reported as stf (about 530 ms instead of 202 ms), which hid most of the combined gain and pointed at the wrong place. The state writer, not the state transition, is now the replay's bottleneck.

Changes

Area Change
storage/state_writer.rs StateWriterHandle::send returns the (start, end) instants around its blocking send
storage/store.rs insert_state records the hand-off span (first start, last end if repeated) in a shared field; new Store::take_state_handoff() takes and clears it
blockchain/import_timing.rs writer_wait_start/writer_wait_end on ImportTimings and StoreTimings, copied in absorb_store; new writer_wait row after stf; header documents the nesting
blockchain/lib.rs Beacon arm takes the hand-off instants right after on_block returns (both Ok and Err); clears any stale span before the call
blockchain/metrics.rs writer_wait added to BLOCK_IMPORT_PHASES (the phase label list)
docs/metrics.md, docs/benchmarking.md Phase documented; beacon stf now excludes the wait

The replay benchmark builds its phases map from BLOCK_IMPORT_PHASES and the same histogram, so it picks up writer_wait and the exclusive stf with no code change.

One beacon on_block makes one insert_state call. The store still merges repeated calls (first start, last end), the module's convention for repeated sections.

Semantics change

Beacon stf (the report row and the lean_block_import_phase_seconds{phase="stf"} series) now excludes the writer wait: it is the on_block span minus writer_wait, saturating at zero. The rows still sum to the end-to-end time. Lean blocks never set the new instants, so their stf and report are unchanged. A new phase="writer_wait" series appears on beacon only. Dashboards comparing beacon stf across this change will see it drop by the wait.

Testing

Command Result
cargo fmt --all clean
cargo clippy --workspace --all-targets --profile release-fast -- -D warnings clean
cargo test -p ethlambda-storage --profile release-fast --lib 139 passed, 1 ignored
cargo test -p ethlambda-blockchain --profile release-fast --lib 210 passed, 0 ignored
cargo check -p ethlambda --profile release-fast clean

New tests: stf minus writer_wait, wait absent, wait longer than stf saturating to zero, row order and presence (existing label-list test also covers the new label), and a storage test that insert_state records a start <= end pair and that taking it clears it. Spec suites and the replay benchmark were not run.

Clippy ran without --locked: Cargo.lock on the base (125dce1) is already stale (zk_alloc is listed under the wrong crate), so --locked fails there with or without this change. The lockfile is not part of this PR.

@MegaRedHand MegaRedHand added the beacon Ethereum Beacon Chain client label Oct 2, 2026
MegaRedHand added a commit that referenced this pull request Oct 2, 2026
…3-636-638-gloas-live

Conflicted files:
- crates/storage/src/store.rs (the std imports: this branch's MutexGuard
  plus #651's Instant)

No semantic adaptation was needed: the writer_wait phase, the state handoff
timing and the replay --block-delay flag do not touch gloas-specific code, and
the import timing rows are fork-agnostic. The branch sits on bci 125dce1, so
this also brings main's #641 (one dedicated prover thread) with its crypto
tests.

Cargo.lock: the merge adds the zk_alloc dev-dependency to ethlambda-crypto,
and the stale lockfile this branch inherits records zk_alloc under another
crate. The lockfile is left exactly as on the first parent; builds here run
without --locked.
MegaRedHand added a commit that referenced this pull request Oct 5, 2026
Base automatically changed from beacon-chain-integration to main October 20, 2026 16:19
Beacon post-states are persisted by one background thread behind a bounded
queue, and Store::insert_state blocks on it while the queue is full. That
call sits inside fork_choice::on_block, which the chain actor times as the
stf phase, so when blocks import faster than the writer persists them the
importer's wait was reported as state-transition time.

StateWriterHandle::send now returns the instants around its blocking send,
insert_state keeps the span (first start, last end) and
Store::take_state_handoff hands it to the chain actor, which records it as
writer_wait_start/end. The report gains a writer_wait row after stf, and the
phase label is added to lean_block_import_phase_seconds.

Semantics change: beacon stf now excludes the writer wait (saturating
subtraction in the report), so the rows still sum to the end-to-end time.
Lean never records a wait, so its report is unchanged.
The replay feeds blocks back to back, while a live node gets one per slot.
When the build imports faster than the background state writer persists
post-states, the writer's queue fills and the importer blocks in
writer_wait, so the replay measures the writer instead of the import (one
merged build waited 326 ms per block).

--block-delay <MILLISECONDS> (default 0, today's behavior) sleeps after each
block's import, warm-up included, once its phases and wall time are
recorded, so the sleep sits in no per-block phase, no wall_seconds and no
summary row. The delay is recorded as params.block_delay_ms in the JSON
report and printed in the human header.
@MegaRedHand
MegaRedHand force-pushed the feat/beacon-import-writer-wait branch from 3abb3cc to 5654226 Compare October 20, 2026 17:32
MegaRedHand added a commit that referenced this pull request Oct 21, 2026
…651)

Squash of feat/beacon-import-writer-wait at 5654226 (merge-base 35c074b).
@MegaRedHand
MegaRedHand marked this pull request as ready for review October 26, 2026 16:10
@github-actions

Copy link
Copy Markdown

🤖 Claude Code Review

Review of PR 651: writer_wait phase and --block-delay for the import benchmark

The change is small, well documented and tested. I found no correctness or consensus-layer problems. It only touches benchmark and timing code, plus a return value on StateWriterHandle::send.

Point 1: the span over-reports the wait when on_block hands off more than once.

  • crates/storage/src/store.rs, insert_state: repeated hand-offs are folded into one span from the first start to the last end.
  • That span also covers the work between hand-offs, so it counts as writer_wait and is subtracted from stf.
  • If on_block calls insert_state once per block, this is exact. Please confirm that holds for every fork path, including fork-upgrade paths that might write an intermediate state.
  • If it can be more than once, summing the individual end - start durations would be accurate. That needs a Duration accumulator in place of the (Instant, Instant) pair. The cost is that the row no longer has real start and end instants.

Point 2: the handoff slot is shared state, so concurrent inserts can mix into the span.

  • The slot lives in an Arc<Mutex<…>> shared across all Store clones.
  • crates/blockchain/src/lib.rs clears it just before on_block as a mitigation.
  • Another clone calling insert_state while on_block runs, for example a p2p-side or fetch path, would leak into this block's wait.
  • That is probably impossible today, because the chain actor is the only writer. A short comment at the take_state_handoff call saying so would help.
  • Lean imports record a hand-off and never take it. The next beacon block's pre-clear drops it, so this is harmless. It only costs a mutex lock per lean insert_state.

Point 3: smaller notes.

  • The .unwrap() on the mutex in insert_state and take_state_handoff follows the file's existing style. A poisoned lock would panic the importer, but the critical sections are trivial.
  • In rows(), saturating_sub hides a wait longer than stf, which can't legitimately happen. That is fine defensively, and the saturation test covers it.
  • pause_between_blocks runs after finish_at_most_once and the sample are recorded in both loops, so the sleep stays out of every measured span. Putting it in the warmup loop as well keeps the writer in the same drained state for the measured blocks. The 0 default leaves existing behavior unchanged.
  • block_delay_ms is added to Params, the JSON report and the human header, and docs/benchmarking.md and docs/metrics.md are updated. The BLOCK_IMPORT_PHASES addition is placed in crossing order.
  • Docs nit in docs/benchmarking.md: the phase-list paragraph now has an over-long line after the reflow (`block_atts`; plus the per-arrival sections…). It is cosmetic.

Verdict: looks good. Points 1 and 2 are optional hardening.


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

@github-actions

Copy link
Copy Markdown

🤖 Codex Code Review

Looks good overall. The PR is narrowly scoped, the timing split is well-tested, and I don’t see a consensus-safety regression in fork choice, attestation handling, justification/finalization, STF logic, XMSS, or SSZ from these changes.

  • No correctness issue in the new --block-delay path: the sleep is added after sample collection in bin/ethlambda/src/benchmark/import/replay.rs:133 and bin/ethlambda/src/benchmark/import/replay.rs:159, so it does not contaminate per-block timing.
  • The writer_wait extraction is conceptually sound: crates/blockchain/src/lib.rs:1792 clears stale handoff state before fork_choice::on_block, then reads the new span immediately after at crates/blockchain/src/lib.rs:1803. That makes the imported block’s timing self-contained.
  • The storage-side accumulation also matches the stated semantics: crates/storage/src/store.rs:2915 preserves the first start and last end across repeated inserts until take_state_handoff(), and crates/storage/src/store.rs:2929 clears it on read.

One minor risk to keep an eye on:

  • state_handoff is shared across all Store clones via Arc<Mutex<...>> in crates/storage/src/store.rs:934. That is fine if block import remains single-threaded per store instance, but it would become attribution-fragile if two imports could call insert_state concurrently on cloned stores. In that case, one import could observe another’s handoff span. If concurrent imports on the same underlying Store are possible now or planned, consider keying handoff timing by block root or by import context rather than storing a single global pending span.

No performance concern beyond the intentional benchmark-only delay, and the new tests/docs are appropriate.


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

@github-actions

Copy link
Copy Markdown

🤖 Kimi Code Review

I'll review this PR which adds a block_delay benchmark option and separates writer_wait timing from stf in beacon block import metrics.

Overall Assessment

The PR is well-structured and addresses a real benchmarking need: preventing back-to-back block replay from saturating the background state writer queue, which would distort stf measurements. The implementation is mostly correct, but I have several concerns ranging from minor code quality issues to a potential correctness bug in timing subtraction.


Critical Issues

1. Potential Panic: saturating_sub on Duration with Instant-derived values (crates/blockchain/src/import_timing.rs:374-376)

if let (Some(total), Some(wait)) = (stf.elapsed, writer_wait.elapsed) {
    stf.elapsed = Some(total.saturating_sub(wait));
}

Problem: While saturating_sub prevents panic on underflow, the test at line 898-908 ("a_writer_wait_longer_than_stf_saturates_stf_to_zero") explicitly validates this saturates to zero. However, this indicates a measurement bug in the caller: if writer_wait exceeds stf, the stf span was incorrectly bracketed or writer_wait leaked outside it.

More critically: The Row::elapsed field is computed as end - start from Instant pairs. Instant subtraction can panic on platforms where end < start due to non-monotonic clocks (rare but possible with VM migration, NTP step, etc.). The existing Row::new doesn't use saturating_sub:

// Row::new (implied from usage)
fn new(name: &'static str, start: Option<Instant>, end: Option<Instant>) -> Row {
    // ...
    elapsed: start.zip(end).map(|(s, e)| e - s), // can panic!
}

Recommendation: Defensive programming: use e.saturating_duration_since(s) in Row::new. At minimum, audit all Instant subtractions in this file.


2. Double pause_between_blocks Call in replay_corpus (bin/ethlambda/src/benchmark/import/replay.rs)

Looking at the control flow:

First call (line 133, in the for position in 0..options.warmup_blocks loop):

pause_between_blocks(options.block_delay).await;

Second call (line 160, after finish_at_most_once):

pause_between_blocks(options.block_delay).await;

But the second call is inside the for position in options.warmup_blocks..total loop, after the sample is recorded. The comment says "After finish_at_most_once and the sample are recorded" — but finish_at_most_once is called before the second sleep, at line 156-159.

Wait — let me re-read. The second sleep is at line 160, after finish_at_most_once. But finish_at_most_once is called with the outcome from import_block. Looking more carefully:

for position in options.warmup_blocks..total {
    // ... import block ...
    let (timings, outcome) = blockchain.import_block(...).await;
    // ... record phases ...
    finish_at_most_once(position, outcome, phases);  // line ~156
    pause_between_blocks(options.block_delay).await; // line ~160
}

This looks correct — the sleep is after recording. But the first loop (warmup) also has the sleep at its end. However, there's a subtle issue: the first loop's sleep happens after the info! log but the loop variable position is used in the log. The sleep is outside measured spans, which is correct.

Actual bug: The first loop's sleep is at the end of the loop body, but there's no sleep before the first iteration. For warmup, this means the first warmup block immediately follows anchor loading with no delay. This is probably fine since warmup isn't measured, but if the intent is to drain the writer before measured blocks, consider adding a sleep before the measured loop too.

Actually, re-reading: the comment says "so the background state writer can drain between blocks". The first measured block follows the last warmup block with a delay (from the first loop's last iteration). This seems correct.


Security & Correctness Issues

3. Mutex Overhead and Potential Contention (crates/storage/src/store.rs:1566, 2912-2916)

state_handoff: Arc<Mutex<Option<(Instant, Instant)>>>,
let mut handoff = self.state_handoff.lock().unwrap();
*handoff = Some(match *handoff {
    Some((first, _)) => (first, end),
    None => (start, end),
});

Problem: Every insert_state takes a global mutex on Store — which is already Clone/Arc-based for sharing. The state_handoff is Arc<Mutex<...>>, so all clones share it. insert_state is on the hot path of block import.

Impact: Low but non-zero. The critical section is tiny (two Instant copies and an Option update), but in a high-throughput benchmark this could add jitter.

Recommendation: Consider AtomicU64 pairs or a lock-free structure if this becomes measurable. For now, document the assumption that this is acceptable. The Mutex is std::sync::Mutex, not parking_lot — consider if parking_lot::Mutex would reduce overhead (though this adds a dependency).

4. unwrap() in take_state_handoff (crates/storage/src/store.rs:2929)

pub fn take_state_handoff(&self) -> Option<(Instant, Instant)> {
    self.state_handoff.lock().unwrap().take()
}

Problem: Mutex::lock().unwrap() panics if the mutex is poisoned. In a blockchain client, panics should be avoided or converted to errors. While poisoned mutexes are rare and usually indicate a bug, this could crash the node.

Recommendation: Use lock().unwrap_or_else(|e| e.into_inner()) to recover from poison, or return Result. Given this is diagnostic/metrics code, graceful degradation is preferable to crashing.


Code Quality & Maintainability

5. Inconsistent pause_between_blocks Placement (bin/ethlambda/src/benchmark/import/replay.rs)

The function is called in two places with different comments:

  • Line 133: no comment (implicit)
  • Line 160: detailed comment about being outside measured spans

But the first call is also outside measured spans (the wall_seconds and phases are only in the second loop). Add a similar comment to the first call for clarity, or extract to a helper that documents this invariant.

6. take_state_handoff Naming vs. Semantics (crates/storage/src/store.rs:2924-2930)

The name suggests "take and clear", which is correct. But the doc comment says "Takes the span insert_state spent handing states to the writer since the last call, clearing it."

Minor issue: "since the last call" is slightly ambiguous — it means "since the last take_state_handoff call", not "since the last insert_state call". The implementation is correct (keeps first start, last end across multiple inserts), but the phrasing could be clearer: "since the last take" or "across all inserts since the last take".

7. Missing writer_wait in StoreTimings Documentation (crates/blockchain/src/import_timing.rs)

The module-level doc comment was updated (lines 53-60), but StoreTimings itself lacks a doc comment for the new fields. Add:

/// Beacon: start/end of blocking on the state writer's full queue.
/// Nested inside `stf`; subtracted from it in reports.
pub writer_wait_start: Option<Instant>,
pub writer_wait_end: Option<Instant>,

8. Test Duplication (crates/blockchain/src/import_timing.rs:855-908)

The three new tests (the_stf_row_excludes_the_writer_wait, an_absent_writer_wait_leaves_stf_unchanged, a_writer_wait_longer_than_stf_saturates_stf_to_zero) are good but row_elapsed helper is local to the test module. Consider if it should be a #[cfg(test)] utility or if Row should expose elapsed_for_test().


Performance Considerations

9. tokio::time::sleep(0) Still Yields (bin/ethlambda/src/benchmark/import/replay.rs:170-175)

async fn pause_between_blocks(delay_ms: u64) {
    if delay_ms > 0 {
        tokio::time::sleep(Duration::from_millis(delay_ms)).await;
    }
}

The if guard prevents a zero-duration sleep, which is good — tokio::time::sleep(0) would still yield to the scheduler. Verified by the default of 0 being fast-path.

10. block_delay Type: u64 milliseconds vs. Duration (bin/ethlambda/src/benchmark/import/mod.rs:92)

pub block_delay: u64,

Question: Is u64 milliseconds sufficient? Maximum is ~584 million years, so practically yes. But using Duration directly with clap's humantime parser would be more ergonomic (--block-delay 1s500ms). However, this adds a dependency. The current approach is acceptable for a benchmark tool.


Documentation

11. docs/benchmarking.md Inconsistency (docs/benchmarking.md:240-250)

The new documentation says "about a second on mainnet" for state write time. This is a rough estimate that may become stale. Consider qualifying: "as of [date]" or referencing a metric.

Also, the phase list update is correct but note that writer_wait is added between stf and db_write, which matches BLOCK_IMPORT_PHASES and rows() ordering.


Positive Acknowledgments

  1. Correct subtraction semantics: stf minus writer_wait with saturating_sub keeps row sums correct (tested).
  2. Clean separation of concerns: The block_delay is purely in benchmark tooling, not leaking into production code.
  3. Good test coverage: CLI parsing, JSON serialization, timing arithmetic, and store handoff all have tests.
  4. Documentation updates: Both benchmarking.md and metrics.md are updated consistently.
  5. No consensus logic changes: This is purely metrics/benchmarking; no fork choice, attestation, or state transition logic is modified.

Summary Table

Priority File Line Issue Suggested Fix
Medium crates/blockchain/src/import_timing.rs ~355 Instant subtraction may panic Use saturating_duration_since in Row::new
Medium crates/storage/src/store.rs 2929 Mutex::unwrap() may panic on poison Use unwrap_or_else(|e| e.into_inner())
Low crates/storage/src/store.rs 1566 std::sync::Mutex overhead on hot path Consider parking_lot or document acceptance
Low bin/ethlambda/src/benchmark/import/replay.rs 133 Missing comment on first pause_between_blocks Add comment matching line 158-160
Low crates/storage/src/store.rs 2924 Doc comment slightly ambiguous Clarify "since last take" vs "since last insert"
Low crates/blockchain/src/import_timing.rs ~87 Missing field docs for writer_wait_* Add doc comments to StoreTimings fields

The PR is approvable with minor revisions. The saturating_duration_since and poisoned mutex handling are the most important fixes.


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

Main gained the gloas stack (#634, #635, #639, #662, #663); no conflicts.

This branch has not been deployed

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

Labels

beacon Ethereum Beacon Chain client

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant