From d20d6320609febb299b34afb6f82d972cb202369 Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 7 Aug 2026 12:42:19 +1200 Subject: [PATCH 1/7] Add warning per block for snapshot lag --- crates/store/src/state/view/mod.rs | 1 + crates/store/src/state/view/snapshot.rs | 129 +++++++++++++++++------- crates/store/src/state/writer/worker.rs | 18 +++- crates/tracing-macro/src/lib.rs | 1 + 4 files changed, 109 insertions(+), 40 deletions(-) diff --git a/crates/store/src/state/view/mod.rs b/crates/store/src/state/view/mod.rs index 34379c751..283a0bd40 100644 --- a/crates/store/src/state/view/mod.rs +++ b/crates/store/src/state/view/mod.rs @@ -28,6 +28,7 @@ pub use scoped::{ScopedBlockNum, ScopedBlockRange}; mod snapshot; pub(in crate::state) use snapshot::{ PublishedGenerations, + SNAPSHOT_LAG_WARN_THRESHOLD, SNAPSHOTS_LIVE_WARN_THRESHOLD, SnapshotGuard, StateSnapshot, diff --git a/crates/store/src/state/view/snapshot.rs b/crates/store/src/state/view/snapshot.rs index 50ecd3f92..4d68d213c 100644 --- a/crates/store/src/state/view/snapshot.rs +++ b/crates/store/src/state/view/snapshot.rs @@ -40,16 +40,30 @@ const SNAPSHOT_SUPERSEDED_WARN_THRESHOLD: Duration = Duration::from_secs(10); /// Steady state is 1-2 generations: the just-published snapshot plus predecessors briefly pinned /// by in-flight requests. A sustained higher count means slow or leaked readers are holding old /// generations alive (see [`SnapshotGuard`]). -pub(in crate::state) const SNAPSHOTS_LIVE_WARN_THRESHOLD: u64 = 4; +pub(in crate::state) const SNAPSHOTS_LIVE_WARN_THRESHOLD: u64 = 3; + +/// Snapshot lag (in blocks) above which the block writer logs a warning on each applied block. +/// +/// The lag is the distance between the chain tip and the oldest still-pinned snapshot generation +/// (see [`GenerationsStatus::oldest_pinned`]), uncapped: unlike the prune tip, the reported lag +/// keeps growing past [`SNAPSHOT_PRUNE_LAG_CAP`], so a leaked reader keeps warning for as long as +/// it pins its generation. Steady state is 1-2 blocks: readers are request-scoped, so old +/// generations are released within a block interval or two. A sustained higher lag means a slow or +/// leaked reader is pinning an old generation, holding back SQLite history pruning and retaining +/// `RocksDB` garbage. Unlike the release-time lifetime warning (see [`SnapshotGuard`]), this fires +/// while the offending reader is still alive, repeating on every applied block until the +/// generation is released. +pub(in crate::state) const SNAPSHOT_LAG_WARN_THRESHOLD: u32 = 3; /// Upper bound on how far the snapshot-aware pruning tip may lag the chain tip. /// /// History pruning keys off the oldest live snapshot generation (see -/// [`PublishedGenerations::prune_tip`]), so a leaked or pathologically slow reader would +/// [`PublishedGenerations::advance`]), so a leaked or pathologically slow reader would /// otherwise stall pruning indefinitely. Beyond this /// many blocks of lag the writer prunes anyway, accepting the historical-read race for that reader -/// (which the snapshot-lifetime warnings have long since reported). One full retention window, so -/// worst-case retained history is bounded at twice the window. +/// (which the per-block snapshot-lag warnings have long since reported and keep reporting; see +/// [`SNAPSHOT_LAG_WARN_THRESHOLD`]). One full retention window, so worst-case retained +/// history is bounded at twice the window. const SNAPSHOT_PRUNE_LAG_CAP: u32 = HISTORICAL_BLOCK_RETENTION; // PUBLISHED GENERATIONS @@ -60,9 +74,11 @@ const SNAPSHOT_PRUNE_LAG_CAP: u32 = HISTORICAL_BLOCK_RETENTION; /// /// Owned exclusively by the writer — no locks or shared state. Liveness is not tracked /// separately: a [`Weak`] per generation asks the snapshot's own [`Arc`] refcount, which is the -/// ground truth for "some reader can still see this height". Dead and no-longer-relevant entries -/// are discarded on each [`Self::prune_tip`] call (once per applied block), which bounds the -/// deque to roughly [`SNAPSHOT_PRUNE_LAG_CAP`] entries even when a reader leaks its snapshot. +/// ground truth for "some reader can still see this height". Dead entries are discarded on each +/// [`Self::advance`] call (once per applied block); pinned entries are kept regardless of age so +/// the true oldest pinned height stays observable, which bounds the deque to one entry per live +/// snapshot generation (each a height and a [`Weak`], negligible next to the pinned snapshot +/// itself). /// /// Generic over the pinned type for testability; the writer uses `T = StateSnapshot`. pub(in crate::state) struct PublishedGenerations { @@ -84,30 +100,42 @@ impl PublishedGenerations { self.entries.push_back((height, Arc::downgrade(pinned))); } - /// Returns the effective chain tip for history pruning. + /// Discards generations no longer pinned by any reader and reports on those that remain. /// - /// The store's SQLite reads are scoped only by an upper block bound, with no point-in-time - /// protection equivalent to the `RocksDB` snapshots backing the trees. Pruning therefore - /// treats the oldest still-pinned generation as the tip: a generation pinned at height `H` - /// keeps the same retention window it had when `H` was the tip, and pruning simply lags until - /// it is released. The lag is capped at [`SNAPSHOT_PRUNE_LAG_CAP`] blocks so a leaked reader - /// cannot stall pruning indefinitely: entries below the cap's floor are discarded despite - /// still being pinned, as are entries that are no longer pinned. - pub(in crate::state) fn prune_tip(&mut self, chain_tip: BlockNumber) -> BlockNumber { + /// The prune tip is the effective chain tip for history pruning. The store's SQLite reads are + /// scoped only by an upper block bound, with no point-in-time protection equivalent to the + /// `RocksDB` snapshots backing the trees. Pruning therefore treats the oldest still-pinned + /// generation as the tip: a generation pinned at height `H` keeps the same retention window it + /// had when `H` was the tip, and pruning simply lags until it is released. The lag is capped + /// at [`SNAPSHOT_PRUNE_LAG_CAP`] blocks so a leaked reader cannot stall pruning indefinitely: + /// generations below the cap's floor no longer hold pruning back, but stay recorded so + /// [`GenerationsStatus::oldest_pinned`] keeps reporting them for as long as they are pinned. + pub(in crate::state) fn advance(&mut self, chain_tip: BlockNumber) -> GenerationsStatus { + self.entries.retain(|(_, pinned)| pinned.strong_count() > 0); + let oldest_pinned = self.entries.front().map(|(height, _)| *height); + // The prune tip is the oldest pinned generation within the lag cap, or the chain tip. let lag_floor = chain_tip.as_u32().saturating_sub(SNAPSHOT_PRUNE_LAG_CAP); - while let Some((height, pinned)) = self.entries.front() { - // Drop entries below the lag floor or that are no longer pinned. - if height.as_u32() < lag_floor || pinned.strong_count() == 0 { - self.entries.pop_front(); - } else { - break; - } - } - // Return the prune tip, which is the oldest pinned generation or the chain tip. - self.entries.front().map_or(chain_tip, |(height, _)| (*height).min(chain_tip)) + let prune_tip = self + .entries + .iter() + .map(|(height, _)| *height) + .find(|height| height.as_u32() >= lag_floor) + .map_or(chain_tip, |height| height.min(chain_tip)); + GenerationsStatus { prune_tip, oldest_pinned } } } +/// Per-block report on the still-pinned snapshot generations; see +/// [`PublishedGenerations::advance`]. +pub(in crate::state) struct GenerationsStatus { + /// The effective chain tip for history pruning: the oldest still-pinned generation within + /// [`SNAPSHOT_PRUNE_LAG_CAP`], or the chain tip when none is pinned. + pub(in crate::state) prune_tip: BlockNumber, + /// The oldest generation still pinned by any reader, regardless of the lag cap. `None` when no + /// generation is pinned. + pub(in crate::state) oldest_pinned: Option, +} + // SNAPSHOT GUARD // ================================================================================================ @@ -119,7 +147,7 @@ impl PublishedGenerations { /// generation pins a `RocksDB` snapshot, which delays garbage collection of superseded key /// versions during compaction (compaction itself keeps running); the retained garbage grows with /// write churn for as long as the snapshot is held and is reclaimed once it is released. A held -/// generation also holds back SQLite history pruning (see [`PublishedGenerations::prune_tip`]). +/// generation also holds back SQLite history pruning (see [`PublishedGenerations::advance`]). /// /// Readers are expected to be request-scoped, so a superseded generation should be released well /// within a block interval. Outliving supersession by more than @@ -239,12 +267,14 @@ mod tests { use super::*; #[test] - fn prune_tip_tracks_oldest_pinned_height_across_out_of_order_drops() { + fn advance_tracks_oldest_pinned_height_across_out_of_order_drops() { let mut published = PublishedGenerations::::new(); let tip = BlockNumber::from(100); // No live generations: prune at the tip. - assert_eq!(published.prune_tip(tip), tip); + let status = published.advance(tip); + assert_eq!(status.prune_tip, tip); + assert_eq!(status.oldest_pinned, None); let gen_97 = Arc::new(97); let gen_98 = Arc::new(98); @@ -252,24 +282,28 @@ mod tests { published.record(BlockNumber::from(97), &gen_97); published.record(BlockNumber::from(98), &gen_98); published.record(BlockNumber::from(99), &gen_99); - assert_eq!(published.prune_tip(tip), BlockNumber::from(97)); + let status = published.advance(tip); + assert_eq!(status.prune_tip, BlockNumber::from(97)); + assert_eq!(status.oldest_pinned, Some(BlockNumber::from(97))); // Dropping a middle generation leaves the oldest unchanged. drop(gen_98); - assert_eq!(published.prune_tip(tip), BlockNumber::from(97)); + assert_eq!(published.advance(tip).prune_tip, BlockNumber::from(97)); drop(gen_97); - assert_eq!(published.prune_tip(tip), BlockNumber::from(99)); + assert_eq!(published.advance(tip).prune_tip, BlockNumber::from(99)); // A pinned generation never advances pruning past the tip. - assert_eq!(published.prune_tip(BlockNumber::from(98)), BlockNumber::from(98)); + assert_eq!(published.advance(BlockNumber::from(98)).prune_tip, BlockNumber::from(98)); drop(gen_99); - assert_eq!(published.prune_tip(tip), tip); + let status = published.advance(tip); + assert_eq!(status.prune_tip, tip); + assert_eq!(status.oldest_pinned, None); } #[test] - fn prune_tip_discards_leaked_entries_below_the_lag_floor() { + fn advance_caps_prune_lag_but_keeps_reporting_the_leaked_oldest() { let mut published = PublishedGenerations::::new(); let leaked = Arc::new(1); published.record(BlockNumber::from(1), &leaked); @@ -277,11 +311,28 @@ mod tests { // While the leaked generation is within the lag cap it holds pruning back; near genesis the // lag floor saturates to zero. let tip = BlockNumber::from(SNAPSHOT_PRUNE_LAG_CAP); - assert_eq!(published.prune_tip(tip), BlockNumber::from(1)); + let status = published.advance(tip); + assert_eq!(status.prune_tip, BlockNumber::from(1)); + assert_eq!(status.oldest_pinned, Some(BlockNumber::from(1))); - // Once the tip advances past the cap it is discarded despite still being pinned, and no - // longer holds pruning back. + // Once the tip advances past the cap it no longer holds pruning back, but is still reported + // as the oldest pinned generation for as long as it is pinned. let tip = BlockNumber::from(SNAPSHOT_PRUNE_LAG_CAP + 2); - assert_eq!(published.prune_tip(tip), tip); + let status = published.advance(tip); + assert_eq!(status.prune_tip, tip); + assert_eq!(status.oldest_pinned, Some(BlockNumber::from(1))); + + // A newer pinned generation above the floor becomes the prune tip while the leaked one + // still drives the reported lag. + let gen_recent = Arc::new(2); + let recent_height = BlockNumber::from(SNAPSHOT_PRUNE_LAG_CAP + 1); + published.record(recent_height, &gen_recent); + let status = published.advance(tip); + assert_eq!(status.prune_tip, recent_height); + assert_eq!(status.oldest_pinned, Some(BlockNumber::from(1))); + + drop(leaked); + let status = published.advance(tip); + assert_eq!(status.oldest_pinned, Some(recent_height)); } } diff --git a/crates/store/src/state/writer/worker.rs b/crates/store/src/state/writer/worker.rs index 515fb42b6..d75b5294d 100644 --- a/crates/store/src/state/writer/worker.rs +++ b/crates/store/src/state/writer/worker.rs @@ -34,6 +34,7 @@ use crate::state::block_lifecycle::{BlockLifecycle, lifecycle_events_enabled}; use crate::state::loader::TreeStorage; use crate::state::view::{ PublishedGenerations, + SNAPSHOT_LAG_WARN_THRESHOLD, SNAPSHOTS_LIVE_WARN_THRESHOLD, SnapshotGuard, StateSnapshot, @@ -226,7 +227,22 @@ impl WriteWorker { // generation rather than the actual tip: unlike the `RocksDB`-backed trees, SQLite reads // have no point-in-time protection, so pruning lags while pinned views can still reach // the history and catches up once they are released. - let prune_tip = self.published_generations.prune_tip(block_num); + let generations = self.published_generations.advance(block_num); + let snapshot_lag = generations + .oldest_pinned + .map_or(0, |oldest| block_num.as_u32() - oldest.as_u32()); + miden_span_record!(snapshots.lag_blocks = snapshot_lag); + if snapshot_lag > SNAPSHOT_LAG_WARN_THRESHOLD { + tracing::warn!( + target: COMPONENT, + block_num = block_num.as_u32(), + prune_tip = generations.prune_tip.as_u32(), + snapshots.lag_blocks = snapshot_lag, + "a state snapshot is pinned far behind the chain tip; a slow or leaked reader is \ + retaining RocksDB garbage and holding back history pruning", + ); + } + let prune_tip = generations.prune_tip; let resolved_note_ids = self .db .apply_block( diff --git a/crates/tracing-macro/src/lib.rs b/crates/tracing-macro/src/lib.rs index ee76b6ff6..93593bdb3 100644 --- a/crates/tracing-macro/src/lib.rs +++ b/crates/tracing-macro/src/lib.rs @@ -83,6 +83,7 @@ const ALLOWED_FIELD_NAMES: &[&str] = &[ "script.root", "snapshot.block_num", "snapshot.lifetime_ms", + "snapshots.lag_blocks", "snapshots.live", "transaction.id", "transaction.expires_at", From 73472c2bececba5784402e4fe3dfc4a7dc48cad2 Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 7 Aug 2026 12:57:49 +1200 Subject: [PATCH 2/7] Fix field names --- crates/utils/tests/ui/tracing_macros/invalid_field_name.stderr | 2 +- .../ui/tracing_macros/invalid_instrument_field_name.stderr | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/crates/utils/tests/ui/tracing_macros/invalid_field_name.stderr b/crates/utils/tests/ui/tracing_macros/invalid_field_name.stderr index 403f90c3e..5992e7e65 100644 --- a/crates/utils/tests/ui/tracing_macros/invalid_field_name.stderr +++ b/crates/utils/tests/ui/tracing_macros/invalid_field_name.stderr @@ -1,4 +1,4 @@ -error: unsupported tracing field `tx_id`; use one of: account.id, account.id.network_prefix, account.ids, account.ids.count, account.updated, batch.id, batch.account_updates.count, batch.expires_at, batch.expiration_height, batch.input_notes.count, batch.output_notes.count, batch.reference_block.commitment, batch.reference_block.number, block.batch.ids, block.batches.count, block.batches.output_notes.count, block.commitment, block.commitments.account, block.commitments.chain, block.commitments.kernel, block.commitments.note, block.commitments.nullifier, block.commitments.transaction, block.erased_note_proofs.count, block.erased_notes.count, block.from, block.nullifiers.count, block.number, block.output_notes.count, block.prev_block_commitment, block.protocol.version, block.size, block.sub_commitment, block.timestamp, block.transactions.ids, block.transactions.count, block.updated_accounts.count, block_range.from, block_range.to, current_client_block_height, cutoff_block, db.account_state_forest.size, db.account_tree.size, db.block_store.size, db.nullifier_tree.size, db.sqlite.size, db.sqlite.wal.size, dice_roll, failure_rate, finality_level, inputs_size, mempool.accounts, mempool.batches.proposed, mempool.batches.proven, mempool.nullifiers, mempool.output_notes, mempool.transactions.unbatched, mempool.transactions.uncommitted, note.id, notes.count, nullifiers, path, port, prefix_len, prefixes, proof_size, prover, prover.kind, reference_block.number, request.kind, script.root, snapshot.block_num, snapshot.lifetime_ms, snapshots.live, transaction.id, transaction.expires_at, transaction.input_notes.count, transaction.output_notes.count, transaction.reference_block.commitment, transaction.reference_block.number, tip.number, transactions.count, transactions.ids, transactions.input_notes.count, transactions.output_notes.count, transactions.unauthenticated_notes.count, workers.active, workers.capacity, workers.count +error: unsupported tracing field `tx_id`; use one of: account.id, account.id.network_prefix, account.ids, account.ids.count, account.updated, batch.id, batch.account_updates.count, batch.expires_at, batch.expiration_height, batch.input_notes.count, batch.output_notes.count, batch.reference_block.commitment, batch.reference_block.number, block.batch.ids, block.batches.count, block.batches.output_notes.count, block.commitment, block.commitments.account, block.commitments.chain, block.commitments.kernel, block.commitments.note, block.commitments.nullifier, block.commitments.transaction, block.erased_note_proofs.count, block.erased_notes.count, block.from, block.nullifiers.count, block.number, block.output_notes.count, block.prev_block_commitment, block.protocol.version, block.size, block.sub_commitment, block.timestamp, block.transactions.ids, block.transactions.count, block.updated_accounts.count, block_range.from, block_range.to, current_client_block_height, cutoff_block, db.account_state_forest.size, db.account_tree.size, db.block_store.size, db.nullifier_tree.size, db.sqlite.size, db.sqlite.wal.size, dice_roll, failure_rate, finality_level, inputs_size, mempool.accounts, mempool.batches.proposed, mempool.batches.proven, mempool.nullifiers, mempool.output_notes, mempool.transactions.unbatched, mempool.transactions.uncommitted, note.id, notes.count, nullifiers, path, port, prefix_len, prefixes, proof_size, prover, prover.kind, reference_block.number, request.kind, script.root, snapshot.block_num, snapshot.lifetime_ms, snapshots.lag_blocks, snapshots.live, transaction.id, transaction.expires_at, transaction.input_notes.count, transaction.output_notes.count, transaction.reference_block.commitment, transaction.reference_block.number, tip.number, transactions.count, transactions.ids, transactions.input_notes.count, transactions.output_notes.count, transactions.unauthenticated_notes.count, workers.active, workers.capacity, workers.count --> tests/ui/tracing_macros/invalid_field_name.rs:8:9 | 8 | tx_id = %tx_id, diff --git a/crates/utils/tests/ui/tracing_macros/invalid_instrument_field_name.stderr b/crates/utils/tests/ui/tracing_macros/invalid_instrument_field_name.stderr index e37f59b72..7f9a2d77d 100644 --- a/crates/utils/tests/ui/tracing_macros/invalid_instrument_field_name.stderr +++ b/crates/utils/tests/ui/tracing_macros/invalid_instrument_field_name.stderr @@ -1,4 +1,4 @@ -error: unsupported tracing field `tx_id`; use one of: account.id, account.id.network_prefix, account.ids, account.ids.count, account.updated, batch.id, batch.account_updates.count, batch.expires_at, batch.expiration_height, batch.input_notes.count, batch.output_notes.count, batch.reference_block.commitment, batch.reference_block.number, block.batch.ids, block.batches.count, block.batches.output_notes.count, block.commitment, block.commitments.account, block.commitments.chain, block.commitments.kernel, block.commitments.note, block.commitments.nullifier, block.commitments.transaction, block.erased_note_proofs.count, block.erased_notes.count, block.from, block.nullifiers.count, block.number, block.output_notes.count, block.prev_block_commitment, block.protocol.version, block.size, block.sub_commitment, block.timestamp, block.transactions.ids, block.transactions.count, block.updated_accounts.count, block_range.from, block_range.to, current_client_block_height, cutoff_block, db.account_state_forest.size, db.account_tree.size, db.block_store.size, db.nullifier_tree.size, db.sqlite.size, db.sqlite.wal.size, dice_roll, failure_rate, finality_level, inputs_size, mempool.accounts, mempool.batches.proposed, mempool.batches.proven, mempool.nullifiers, mempool.output_notes, mempool.transactions.unbatched, mempool.transactions.uncommitted, note.id, notes.count, nullifiers, path, port, prefix_len, prefixes, proof_size, prover, prover.kind, reference_block.number, request.kind, script.root, snapshot.block_num, snapshot.lifetime_ms, snapshots.live, transaction.id, transaction.expires_at, transaction.input_notes.count, transaction.output_notes.count, transaction.reference_block.commitment, transaction.reference_block.number, tip.number, transactions.count, transactions.ids, transactions.input_notes.count, transactions.output_notes.count, transactions.unauthenticated_notes.count, workers.active, workers.capacity, workers.count +error: unsupported tracing field `tx_id`; use one of: account.id, account.id.network_prefix, account.ids, account.ids.count, account.updated, batch.id, batch.account_updates.count, batch.expires_at, batch.expiration_height, batch.input_notes.count, batch.output_notes.count, batch.reference_block.commitment, batch.reference_block.number, block.batch.ids, block.batches.count, block.batches.output_notes.count, block.commitment, block.commitments.account, block.commitments.chain, block.commitments.kernel, block.commitments.note, block.commitments.nullifier, block.commitments.transaction, block.erased_note_proofs.count, block.erased_notes.count, block.from, block.nullifiers.count, block.number, block.output_notes.count, block.prev_block_commitment, block.protocol.version, block.size, block.sub_commitment, block.timestamp, block.transactions.ids, block.transactions.count, block.updated_accounts.count, block_range.from, block_range.to, current_client_block_height, cutoff_block, db.account_state_forest.size, db.account_tree.size, db.block_store.size, db.nullifier_tree.size, db.sqlite.size, db.sqlite.wal.size, dice_roll, failure_rate, finality_level, inputs_size, mempool.accounts, mempool.batches.proposed, mempool.batches.proven, mempool.nullifiers, mempool.output_notes, mempool.transactions.unbatched, mempool.transactions.uncommitted, note.id, notes.count, nullifiers, path, port, prefix_len, prefixes, proof_size, prover, prover.kind, reference_block.number, request.kind, script.root, snapshot.block_num, snapshot.lifetime_ms, snapshots.lag_blocks, snapshots.live, transaction.id, transaction.expires_at, transaction.input_notes.count, transaction.output_notes.count, transaction.reference_block.commitment, transaction.reference_block.number, tip.number, transactions.count, transactions.ids, transactions.input_notes.count, transactions.output_notes.count, transactions.unauthenticated_notes.count, workers.active, workers.capacity, workers.count --> tests/ui/tracing_macros/invalid_instrument_field_name.rs:5:9 | 5 | tx_id = %"0x1234", From 2832c420b9473b0b205317469a7d669ed7833bbc Mon Sep 17 00:00:00 2001 From: sergerad Date: Mon, 10 Aug 2026 09:33:15 +1200 Subject: [PATCH 3/7] Add stateview drop --- crates/store/src/state/view/mod.rs | 47 +++++++++++++++++++++++-- crates/store/src/state/view/snapshot.rs | 7 ++-- 2 files changed, 48 insertions(+), 6 deletions(-) diff --git a/crates/store/src/state/view/mod.rs b/crates/store/src/state/view/mod.rs index 283a0bd40..9ad4ea843 100644 --- a/crates/store/src/state/view/mod.rs +++ b/crates/store/src/state/view/mod.rs @@ -12,11 +12,14 @@ //! can reach the trees directly. use std::ops::RangeInclusive; +use std::panic::Location; use std::sync::Arc; +use std::time::{Duration, Instant}; use miden_protocol::block::{BlockNumber, Blockchain}; use tracing::Span; +use crate::COMPONENT; use crate::account_state_forest::{AccountStateForest, AccountStateForestBackendReader}; use crate::db::Db; use crate::errors::RangeBeyondTip; @@ -47,18 +50,34 @@ pub use transaction_inputs::TransactionInputs; // STATE VIEW // ================================================================================================ +/// View lifetime above which [`StateView`] logs a warning on drop, attributing the acquiring call +/// site. +/// +/// Views are request-scoped, so one should live for milliseconds; several seconds means a slow or +/// stuck reader pinned a snapshot generation for that long. Unlike [`SnapshotGuard`]'s clock this +/// one starts at acquisition, not supersession — a view cannot observe supersession without +/// shared state, and a request holding a view for seconds is abnormal regardless of whether the +/// chain advanced under it. This is the attribution half of the reader diagnostics: the per-block +/// lag warning (see [`SNAPSHOT_LAG_WARN_THRESHOLD`]) fires while an offender is still alive but +/// cannot name it; this one fires only once the view is released, but says who held it. +const VIEW_LIFETIME_WARN_THRESHOLD: Duration = Duration::from_secs(2); + /// A consistent read view of the store, pinned at its snapshot's block height. /// /// Obtained from [`State::view`]; create one per request and drop it when the request completes. /// Holding a view pins a snapshot generation (and thereby the `RocksDB` snapshots backing the /// trees), so it must not be stored in long-lived structs; leaked or slow readers are reported by -/// the store's snapshot-lifetime warnings. +/// the store's snapshot-lifetime warnings, and a view held past +/// [`VIEW_LIFETIME_WARN_THRESHOLD`] reports the call site that acquired it when dropped. /// /// Reads that are technically not block-scoped (e.g. content-addressed note scripts) also live /// here so that every read path flows through a single, consistently-scoped type. pub struct StateView { snapshot: Arc, db: Arc, + /// The call site that acquired this view, captured via `#[track_caller]` on [`State::view`]. + caller: &'static Location<'static>, + created_at: Instant, } impl State { @@ -73,10 +92,13 @@ impl State { /// be mutually consistent (e.g. a query and the tip it was served at) must share one view via /// [`Self::with_view`]. Binding a view to a variable is also discouraged: it keeps the /// snapshot generation pinned until the end of the scope. + #[track_caller] pub fn view(&self) -> StateView { StateView { snapshot: self.latest_snapshot.load_full(), db: Arc::clone(&self.db), + caller: Location::caller(), + created_at: Instant::now(), } } @@ -98,9 +120,13 @@ impl State { /// its underlying `RocksDB` snapshot, for as long as it runs. The snapshot's lifetime is logged /// as a warning if held too long, but that is a backstop, not a substitute for keeping closures /// short. - pub async fn with_view(&self, f: impl AsyncFnOnce(&StateView) -> R) -> R { + /// + /// Not an `async fn` so that the view — and with it the caller location — is captured when + /// `with_view` is called: `#[track_caller]` does not reach into an async body on stable. + #[track_caller] + pub fn with_view(&self, f: impl AsyncFnOnce(&StateView) -> R) -> impl Future { let view = self.view(); - f(&view).await + async move { f(&view).await } } } @@ -164,3 +190,18 @@ impl StateView { self.with_inner_read_blocking(|snapshot| f(&snapshot.forest)) } } + +impl Drop for StateView { + fn drop(&mut self) { + let held = self.created_at.elapsed(); + if held > VIEW_LIFETIME_WARN_THRESHOLD { + tracing::warn!( + target: COMPONENT, + caller = %self.caller, + block_num = self.snapshot.latest_block_num().as_u32(), + view.lifetime_ms = u64::try_from(held.as_millis()).unwrap_or(u64::MAX), + "state view held for excessive time, pinning its snapshot generation", + ); + } + } +} diff --git a/crates/store/src/state/view/snapshot.rs b/crates/store/src/state/view/snapshot.rs index 4d68d213c..398401829 100644 --- a/crates/store/src/state/view/snapshot.rs +++ b/crates/store/src/state/view/snapshot.rs @@ -50,9 +50,10 @@ pub(in crate::state) const SNAPSHOTS_LIVE_WARN_THRESHOLD: u64 = 3; /// it pins its generation. Steady state is 1-2 blocks: readers are request-scoped, so old /// generations are released within a block interval or two. A sustained higher lag means a slow or /// leaked reader is pinning an old generation, holding back SQLite history pruning and retaining -/// `RocksDB` garbage. Unlike the release-time lifetime warning (see [`SnapshotGuard`]), this fires -/// while the offending reader is still alive, repeating on every applied block until the -/// generation is released. +/// `RocksDB` garbage. Unlike the release-time warnings, this fires while the offending reader is +/// still alive, repeating on every applied block until the generation is released — at which point +/// the [`StateView`](super::StateView) drop warning attributes the call site that held it (and +/// [`SnapshotGuard`] reports the generation's lifetime). pub(in crate::state) const SNAPSHOT_LAG_WARN_THRESHOLD: u32 = 3; /// Upper bound on how far the snapshot-aware pruning tip may lag the chain tip. From 64701c668f76c148784a76779dc89ac8a6c4bf5a Mon Sep 17 00:00:00 2001 From: sergerad Date: Mon, 10 Aug 2026 09:42:26 +1200 Subject: [PATCH 4/7] Update comments --- crates/store/src/state/view/snapshot.rs | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/crates/store/src/state/view/snapshot.rs b/crates/store/src/state/view/snapshot.rs index 398401829..3a18941fb 100644 --- a/crates/store/src/state/view/snapshot.rs +++ b/crates/store/src/state/view/snapshot.rs @@ -6,6 +6,10 @@ //! additionally remembers each published generation in [`PublishedGenerations`], whose oldest //! still-pinned height feeds snapshot-aware history pruning, since SQLite reads have no //! point-in-time protection equivalent to the `RocksDB` snapshots backing the trees. +//! +//! Everything here operates on whole generations; per-reader attribution (which call site pinned +//! a generation, and for how long) lives on [`StateView`](super::StateView), the request-scoped +//! handle through which readers acquire a snapshot. use std::collections::VecDeque; use std::sync::atomic::{AtomicUsize, Ordering}; @@ -51,9 +55,9 @@ pub(in crate::state) const SNAPSHOTS_LIVE_WARN_THRESHOLD: u64 = 3; /// generations are released within a block interval or two. A sustained higher lag means a slow or /// leaked reader is pinning an old generation, holding back SQLite history pruning and retaining /// `RocksDB` garbage. Unlike the release-time warnings, this fires while the offending reader is -/// still alive, repeating on every applied block until the generation is released — at which point -/// the [`StateView`](super::StateView) drop warning attributes the call site that held it (and -/// [`SnapshotGuard`] reports the generation's lifetime). +/// still alive, repeating on every applied block until the generation is released — once it is, +/// the [`StateView`](super::StateView) drop warning attributes the call site that held it (its +/// own lifetime threshold permitting), and [`SnapshotGuard`] reports the generation's lifetime. pub(in crate::state) const SNAPSHOT_LAG_WARN_THRESHOLD: u32 = 3; /// Upper bound on how far the snapshot-aware pruning tip may lag the chain tip. From 62a2880c87dbff330905e6e2a6d6adcd27f8bf8b Mon Sep 17 00:00:00 2001 From: sergerad Date: Tue, 1 Sep 2026 11:44:29 +1200 Subject: [PATCH 5/7] Remove warn log approach and simplify with snapshot span fields --- crates/store/src/state/lifecycle.rs | 16 +- crates/store/src/state/mod.rs | 2 +- crates/store/src/state/view/mod.rs | 65 ++----- crates/store/src/state/view/snapshot.rs | 225 +++++++++--------------- crates/store/src/state/writer/worker.rs | 60 ++----- crates/tracing/src/attribute.rs | 3 +- 6 files changed, 108 insertions(+), 263 deletions(-) diff --git a/crates/store/src/state/lifecycle.rs b/crates/store/src/state/lifecycle.rs index e40d46388..e2d5c562e 100644 --- a/crates/store/src/state/lifecycle.rs +++ b/crates/store/src/state/lifecycle.rs @@ -3,7 +3,6 @@ use std::num::NonZeroUsize; use std::path::Path; use std::sync::Arc; -use std::sync::atomic::AtomicUsize; use arc_swap::ArcSwap; use miden_node_tracing::spawn::spawn_blocking_in_current_span; @@ -32,15 +31,7 @@ use crate::state::loader::{ verify_tree_consistency, }; use crate::state::writer::{WriteRequest, WriteWorker, WriterTask}; -use crate::state::{ - BlockCache, - BlockWriter, - ProofCache, - ProofWriter, - SnapshotGuard, - State, - StateSnapshot, -}; +use crate::state::{BlockCache, BlockWriter, ProofCache, ProofWriter, State, StateSnapshot}; use crate::{COMPONENT, DataDirectory, DatabaseOptions}; /// Awaits a spawned load task, forwarding its result. @@ -276,9 +267,6 @@ impl State { let block_cache = BlockCache::new(BLOCK_CACHE_CAPACITY); let proof_cache = ProofCache::new(PROOF_CACHE_CAPACITY); - // Shared counter of live snapshot generations, for observability. - let snapshots_live = Arc::new(AtomicUsize::new(0)); - // Create the initial snapshot from reader views of the just-loaded trees. let initial_snapshot = Arc::new(StateSnapshot::new( nullifier_tree @@ -289,7 +277,6 @@ impl State { forest .reader() .map_err(|e| StateInitializationError::AccountStateForestIoError(e.as_report()))?, - SnapshotGuard::new(Arc::clone(&snapshots_live), latest_block_num), )); let latest_snapshot = Arc::new(ArcSwap::from(initial_snapshot)); @@ -309,7 +296,6 @@ impl State { account_tree, blockchain, forest, - snapshots_live, apply_block_thread_priority, ); let state = Self { diff --git a/crates/store/src/state/mod.rs b/crates/store/src/state/mod.rs index 3a519e36a..ec61c1131 100644 --- a/crates/store/src/state/mod.rs +++ b/crates/store/src/state/mod.rs @@ -21,8 +21,8 @@ pub use lifecycle::LoadedState; use miden_protocol::block::BlockNumber; pub use replica::{BlockCache, BlockNotification, ProofCache, ProofNotification}; use tokio::sync::watch; +use view::StateSnapshot; pub use view::{ScopedBlockNum, ScopedBlockRange, StateView, TransactionInputs}; -use view::{SnapshotGuard, StateSnapshot}; pub use writer::{BlockWriter, ProofWriter, WriterTask}; use crate::blocks::BlockStore; diff --git a/crates/store/src/state/view/mod.rs b/crates/store/src/state/view/mod.rs index 4b4939b86..2022a02d8 100644 --- a/crates/store/src/state/view/mod.rs +++ b/crates/store/src/state/view/mod.rs @@ -12,14 +12,11 @@ //! can reach the trees directly. use std::ops::RangeInclusive; -use std::panic::Location; use std::sync::Arc; -use std::time::{Duration, Instant}; use miden_node_tracing::Span; use miden_protocol::block::{BlockNumber, Blockchain}; -use crate::COMPONENT; use crate::account_state_forest::{AccountStateForest, AccountStateForestBackendReader}; use crate::db::Db; use crate::errors::RangeBeyondTip; @@ -29,13 +26,7 @@ mod scoped; pub use scoped::{ScopedBlockNum, ScopedBlockRange}; mod snapshot; -pub(in crate::state) use snapshot::{ - PublishedGenerations, - SNAPSHOT_LAG_WARN_THRESHOLD, - SNAPSHOTS_LIVE_WARN_THRESHOLD, - SnapshotGuard, - StateSnapshot, -}; +pub(in crate::state) use snapshot::{PublishedGenerations, StateSnapshot}; mod account; mod batch_inputs; @@ -50,34 +41,21 @@ pub use transaction_inputs::TransactionInputs; // STATE VIEW // ================================================================================================ -/// View lifetime above which [`StateView`] logs a warning on drop, attributing the acquiring call -/// site. -/// -/// Views are request-scoped, so one should live for milliseconds; several seconds means a slow or -/// stuck reader pinned a snapshot generation for that long. Unlike [`SnapshotGuard`]'s clock this -/// one starts at acquisition, not supersession — a view cannot observe supersession without -/// shared state, and a request holding a view for seconds is abnormal regardless of whether the -/// chain advanced under it. This is the attribution half of the reader diagnostics: the per-block -/// lag warning (see [`SNAPSHOT_LAG_WARN_THRESHOLD`]) fires while an offender is still alive but -/// cannot name it; this one fires only once the view is released, but says who held it. -const VIEW_LIFETIME_WARN_THRESHOLD: Duration = Duration::from_secs(2); - /// A consistent read view of the store, pinned at its snapshot's block height. /// /// Obtained from [`State::view`]; create one per request and drop it when the request completes. /// Holding a view pins a snapshot generation (and thereby the `RocksDB` snapshots backing the -/// trees), so it must not be stored in long-lived structs; leaked or slow readers are reported by -/// the store's snapshot-lifetime warnings, and a view held past -/// [`VIEW_LIFETIME_WARN_THRESHOLD`] reports the call site that acquired it when dropped. +/// trees), so it must not be stored in long-lived structs. The block writer records the span +/// fields `snapshots.lag_blocks`, `snapshots.oldest_superseded_for_ms`, and `snapshots.live` on +/// each applied block. Those fields show that some reader pins an old generation. Views are +/// acquired inside instrumented request spans, so the span durations bound the hold time and +/// identify the reader. /// /// Reads that are technically not block-scoped (e.g. content-addressed note scripts) also live /// here so that every read path flows through a single, consistently-scoped type. pub struct StateView { snapshot: Arc, db: Arc, - /// The call site that acquired this view, captured via `#[track_caller]` on [`State::view`]. - caller: &'static Location<'static>, - created_at: Instant, } impl State { @@ -92,13 +70,10 @@ impl State { /// be mutually consistent (e.g. a query and the tip it was served at) must share one view via /// [`Self::with_view`]. Binding a view to a variable is also discouraged: it keeps the /// snapshot generation pinned until the end of the scope. - #[track_caller] pub fn view(&self) -> StateView { StateView { snapshot: self.latest_snapshot.load_full(), db: Arc::clone(&self.db), - caller: Location::caller(), - created_at: Instant::now(), } } @@ -117,16 +92,11 @@ impl State { /// /// Work in the closure should be kept to low-complexity compute over the view, ideally with no /// I/O and no other `.await` points. Anything slower holds the pinned snapshot, and therefore - /// its underlying `RocksDB` snapshot, for as long as it runs. The snapshot's lifetime is logged - /// as a warning if held too long, but that is a backstop, not a substitute for keeping closures - /// short. - /// - /// Not an `async fn` so that the view — and with it the caller location — is captured when - /// `with_view` is called: `#[track_caller]` does not reach into an async body on stable. - #[track_caller] - pub fn with_view(&self, f: impl AsyncFnOnce(&StateView) -> R) -> impl Future { + /// its underlying `RocksDB` snapshot, for as long as it runs. The block writer's per-block + /// snapshot span fields expose generations that stay pinned too long. + pub async fn with_view(&self, f: impl AsyncFnOnce(&StateView) -> R) -> R { let view = self.view(); - async move { f(&view).await } + f(&view).await } } @@ -190,18 +160,3 @@ impl StateView { self.with_inner_read_blocking(|snapshot| f(&snapshot.forest)) } } - -impl Drop for StateView { - fn drop(&mut self) { - let held = self.created_at.elapsed(); - if held > VIEW_LIFETIME_WARN_THRESHOLD { - tracing::warn!( - target: COMPONENT, - caller = %self.caller, - block_num = self.snapshot.latest_block_num().as_u32(), - view.lifetime_ms = u64::try_from(held.as_millis()).unwrap_or(u64::MAX), - "state view held for excessive time, pinning its snapshot generation", - ); - } - } -} diff --git a/crates/store/src/state/view/snapshot.rs b/crates/store/src/state/view/snapshot.rs index 9fd610cca..c9ead7b8a 100644 --- a/crates/store/src/state/view/snapshot.rs +++ b/crates/store/src/state/view/snapshot.rs @@ -1,27 +1,23 @@ //! In-memory snapshot machinery for lock-free reads. //! //! Readers access the store's tree state through immutable [`StateSnapshot`] snapshots published -//! by the block writer after each committed block. [`SnapshotGuard`] tracks how many snapshot -//! generations are pinned by readers, since each generation pins a `RocksDB` snapshot. The writer -//! additionally remembers each published generation in [`PublishedGenerations`], whose oldest -//! still-pinned height feeds snapshot-aware history pruning, since SQLite reads have no -//! point-in-time protection equivalent to the `RocksDB` snapshots backing the trees. +//! by the block writer after each committed block. The writer remembers each published generation +//! in [`PublishedGenerations`]. The oldest still-pinned height feeds snapshot-aware history +//! pruning, since SQLite reads have no point-in-time protection equivalent to the `RocksDB` +//! snapshots backing the trees. The same log supplies the per-block snapshot span fields that +//! expose slow or leaked readers. //! -//! Everything here operates on whole generations; per-reader attribution (which call site pinned -//! a generation, and for how long) lives on [`StateView`](super::StateView), the request-scoped -//! handle through which readers acquire a snapshot. +//! Everything here operates on whole generations. Readers acquire a snapshot through +//! [`StateView`](super::StateView), the request-scoped handle. use std::collections::VecDeque; -use std::sync::atomic::{AtomicUsize, Ordering}; -use std::sync::{Arc, OnceLock, Weak}; +use std::sync::{Arc, Weak}; use std::time::{Duration, Instant}; -use miden_node_tracing::{debug, warn}; use miden_protocol::block::nullifier_tree::NullifierTree; use miden_protocol::block::{BlockNumber, Blockchain}; use miden_protocol::crypto::merkle::smt::LargeSmt; -use crate::COMPONENT; use crate::account_state_forest::{ AccountStateForest, AccountStateForestBackendReader, @@ -30,46 +26,14 @@ use crate::account_state_forest::{ use crate::accounts::AccountTreeWithHistory; use crate::state::loader::TreeStorageReader; -/// Time held past supersession above which [`SnapshotGuard`] logs a warning on release. -/// -/// Readers are expected to be request-scoped, so a superseded generation outliving several block -/// intervals indicates a slow or leaked reader pinning a `RocksDB` snapshot (see -/// [`SnapshotGuard`]). The clock starts at supersession rather than creation: the latest -/// generation is always pinned by the published pointer, so time spent as the current generation -/// (idle chains, shutdown) says nothing about reader behaviour. -const SNAPSHOT_SUPERSEDED_WARN_THRESHOLD: Duration = Duration::from_secs(10); - -/// Number of live snapshot generations above which the block writer logs a warning after -/// publishing a new snapshot. -/// -/// Steady state is 1-2 generations: the just-published snapshot plus predecessors briefly pinned -/// by in-flight requests. A sustained higher count means slow or leaked readers are holding old -/// generations alive (see [`SnapshotGuard`]). -pub(in crate::state) const SNAPSHOTS_LIVE_WARN_THRESHOLD: u64 = 3; - -/// Snapshot lag (in blocks) above which the block writer logs a warning on each applied block. -/// -/// The lag is the distance between the chain tip and the oldest still-pinned snapshot generation -/// (see [`GenerationsStatus::oldest_pinned`]), uncapped: unlike the prune tip, the reported lag -/// keeps growing past [`SNAPSHOT_PRUNE_LAG_CAP`], so a leaked reader keeps warning for as long as -/// it pins its generation. Steady state is 1-2 blocks: readers are request-scoped, so old -/// generations are released within a block interval or two. A sustained higher lag means a slow or -/// leaked reader is pinning an old generation, holding back SQLite history pruning and retaining -/// `RocksDB` garbage. Unlike the release-time warnings, this fires while the offending reader is -/// still alive, repeating on every applied block until the generation is released — once it is, -/// the [`StateView`](super::StateView) drop warning attributes the call site that held it (its -/// own lifetime threshold permitting), and [`SnapshotGuard`] reports the generation's lifetime. -pub(in crate::state) const SNAPSHOT_LAG_WARN_THRESHOLD: u32 = 3; - /// Upper bound on how far the snapshot-aware pruning tip may lag the chain tip. /// /// History pruning keys off the oldest live snapshot generation (see /// [`PublishedGenerations::advance`]), so a leaked or pathologically slow reader would -/// otherwise stall pruning indefinitely. Beyond this -/// many blocks of lag the writer prunes anyway, accepting the historical-read race for that reader -/// (which the per-block snapshot-lag warnings have long since reported and keep reporting; see -/// [`SNAPSHOT_LAG_WARN_THRESHOLD`]). One full retention window, so worst-case retained -/// history is bounded at twice the window. +/// otherwise stall pruning indefinitely. Beyond this many blocks of lag the writer prunes anyway +/// and accepts the historical-read race for that reader. The `snapshots.lag_blocks` span field +/// reports the lag on each applied block (see [`GenerationsStatus::oldest_pinned`]). The cap is +/// one full retention window, so worst-case retained history is bounded at twice the window. const SNAPSHOT_PRUNE_LAG_CAP: u32 = HISTORICAL_BLOCK_RETENTION; // PUBLISHED GENERATIONS @@ -83,13 +47,26 @@ const SNAPSHOT_PRUNE_LAG_CAP: u32 = HISTORICAL_BLOCK_RETENTION; /// ground truth for "some reader can still see this height". Dead entries are discarded on each /// [`Self::advance`] call (once per applied block); pinned entries are kept regardless of age so /// the true oldest pinned height stays observable, which bounds the deque to one entry per live -/// snapshot generation (each a height and a [`Weak`], negligible next to the pinned snapshot -/// itself). +/// snapshot generation (each entry is small next to the pinned snapshot itself). /// /// Generic over the pinned type for testability; the writer uses `T = StateSnapshot`. pub(in crate::state) struct PublishedGenerations { /// Published generations in ascending height order. - entries: VecDeque<(BlockNumber, Weak)>, + entries: VecDeque>, +} + +/// One published snapshot generation tracked by [`PublishedGenerations`]. +struct Generation { + height: BlockNumber, + /// The time when a successor generation was published. `None` while this is the latest + /// generation. + /// + /// [`PublishedGenerations::record`] sets this field on the previous back entry. Reader + /// behaviour is measured from supersession, not from publication: the published pointer + /// always pins the latest generation, so time spent as the latest generation gives no + /// information about readers. + superseded_at: Option, + pinned: Weak, } impl PublishedGenerations { @@ -97,13 +74,30 @@ impl PublishedGenerations { Self { entries: VecDeque::new() } } - /// Records a newly published generation. Heights must be recorded in ascending order. + /// Records a newly published generation and marks the previous latest generation as superseded. + /// Heights must be recorded in ascending order. pub(in crate::state) fn record(&mut self, height: BlockNumber, pinned: &Arc) { debug_assert!( - self.entries.back().is_none_or(|(back, _)| *back < height), + self.entries.back().is_none_or(|back| back.height < height), "generation {height} published out of order", ); - self.entries.push_back((height, Arc::downgrade(pinned))); + // The new generation supersedes the previous back entry. + if let Some(previous) = self.entries.back_mut() { + previous.superseded_at = Some(Instant::now()); + } + self.entries.push_back(Generation { + height, + superseded_at: None, + pinned: Arc::downgrade(pinned), + }); + } + + /// Returns the number of recorded generations. + /// + /// Only [`Self::advance`] discards dead generations, so the count is exact directly after + /// `advance` and is an upper bound on the live count between calls. + pub(in crate::state) fn live(&self) -> usize { + self.entries.len() } /// Discards generations no longer pinned by any reader and reports on those that remain. @@ -117,17 +111,24 @@ impl PublishedGenerations { /// generations below the cap's floor no longer hold pruning back, but stay recorded so /// [`GenerationsStatus::oldest_pinned`] keeps reporting them for as long as they are pinned. pub(in crate::state) fn advance(&mut self, chain_tip: BlockNumber) -> GenerationsStatus { - self.entries.retain(|(_, pinned)| pinned.strong_count() > 0); - let oldest_pinned = self.entries.front().map(|(height, _)| *height); + self.entries.retain(|generation| generation.pinned.strong_count() > 0); + let oldest = self.entries.front(); + let oldest_pinned = oldest.map(|generation| generation.height); + let oldest_superseded_for = + oldest.and_then(|generation| generation.superseded_at).map(|at| at.elapsed()); // The prune tip is the oldest pinned generation within the lag cap, or the chain tip. let lag_floor = chain_tip.as_u32().saturating_sub(SNAPSHOT_PRUNE_LAG_CAP); let prune_tip = self .entries .iter() - .map(|(height, _)| *height) + .map(|generation| generation.height) .find(|height| height.as_u32() >= lag_floor) .map_or(chain_tip, |height| height.min(chain_tip)); - GenerationsStatus { prune_tip, oldest_pinned } + GenerationsStatus { + prune_tip, + oldest_pinned, + oldest_superseded_for, + } } } @@ -140,79 +141,11 @@ pub(in crate::state) struct GenerationsStatus { /// The oldest generation still pinned by any reader, regardless of the lag cap. `None` when no /// generation is pinned. pub(in crate::state) oldest_pinned: Option, -} - -// SNAPSHOT GUARD -// ================================================================================================ - -/// RAII member of [`StateSnapshot`] that tracks the number of live snapshot generations. -/// -/// [`StateSnapshot`] is dropped exactly when the last [`Arc`] reference to it is released, so the -/// shared counter reports how many distinct snapshot generations are currently pinned by readers. -/// A sustained count above 1-2 means slow readers are holding old generations alive. Each -/// generation pins a `RocksDB` snapshot, which delays garbage collection of superseded key -/// versions during compaction (compaction itself keeps running); the retained garbage grows with -/// write churn for as long as the snapshot is held and is reclaimed once it is released. A held -/// generation also holds back SQLite history pruning (see [`PublishedGenerations::advance`]). -/// -/// Readers are expected to be request-scoped, so a superseded generation should be released well -/// within a block interval. Outliving supersession by more than -/// [`SNAPSHOT_SUPERSEDED_WARN_THRESHOLD`] is logged at warn level; a generation that is never -/// superseded (the latest at shutdown) is released silently regardless of age. -pub(in crate::state) struct SnapshotGuard { - live: Arc, - created_at: Instant, - /// Set by the writer when a newer generation replaces this one as the published snapshot. - superseded_at: OnceLock, - block_num: BlockNumber, -} - -impl SnapshotGuard { - pub(in crate::state) fn new(live: Arc, block_num: BlockNumber) -> Self { - live.fetch_add(1, Ordering::Relaxed); - Self { - live, - created_at: Instant::now(), - superseded_at: OnceLock::new(), - block_num, - } - } - - /// Marks this generation as superseded by a newer published snapshot, starting the clock - /// against which slow readers are measured. Only the first call takes effect. - pub(in crate::state) fn mark_superseded(&self) { - let _ = self.superseded_at.set(Instant::now()); - } -} - -impl Drop for SnapshotGuard { - fn drop(&mut self) { - let remaining = self.live.fetch_sub(1, Ordering::Relaxed) - 1; - let lifetime_ms = u64::try_from(self.created_at.elapsed().as_millis()).unwrap_or(u64::MAX); - let block_num = self.block_num.as_u32(); - let superseded_for = self.superseded_at.get().map(Instant::elapsed); - if let Some(superseded_for) = - superseded_for.filter(|held| *held > SNAPSHOT_SUPERSEDED_WARN_THRESHOLD) - { - let superseded_for_ms = u64::try_from(superseded_for.as_millis()).unwrap_or(u64::MAX); - warn!( - target: COMPONENT, - "State snapshot held for excessive time after supersession", - block.number = block_num, - snapshot.lifetime_ms = lifetime_ms, - snapshot.superseded_for_ms = superseded_for_ms, - snapshots.live = remaining - ); - } else { - debug!( - target: COMPONENT, - "State snapshot released", - block.number = block_num, - snapshot.lifetime_ms = lifetime_ms, - snapshots.live = remaining - ); - } - } + /// The time since the oldest pinned generation was superseded. `None` when that generation is + /// still the latest generation, or when no generation is pinned. In steady state the value is + /// `None` or much smaller than one block interval. A value that grows across blocks means a + /// slow or leaked reader pins an old generation. + pub(in crate::state) oldest_superseded_for: Option, } // STATE SNAPSHOT @@ -224,6 +157,11 @@ impl Drop for SnapshotGuard { /// [`AccountStateForestBackendReader`]), so any number of readers can access the data concurrently /// without holding a lock and without blocking the writer. /// +/// A pinned snapshot pins the `RocksDB` snapshots that back the trees. A pinned `RocksDB` +/// snapshot delays garbage collection of superseded key versions during compaction; compaction +/// itself continues. A pinned snapshot also holds back SQLite history pruning (see +/// [`PublishedGenerations::advance`]). +/// /// The writer and lifecycle can *construct* snapshots via [`Self::new`], but the fields are only /// readable within the view module tree: every read outside it must go through /// [`StateView`](super::StateView). @@ -232,34 +170,24 @@ pub(in crate::state) struct StateSnapshot { pub(super) blockchain: Blockchain, pub(super) account_tree: AccountTreeWithHistory, pub(super) forest: AccountStateForest, - /// Keeps the live-snapshot count accurate; see [`SnapshotGuard`]. - guard: SnapshotGuard, } impl StateSnapshot { - /// Assembles a snapshot from reader views of the trees and the guard tracking its generation. + /// Assembles a snapshot from reader views of the trees. pub(in crate::state) fn new( nullifier_tree: NullifierTree>, blockchain: Blockchain, account_tree: AccountTreeWithHistory, forest: AccountStateForest, - guard: SnapshotGuard, ) -> Self { Self { nullifier_tree, blockchain, account_tree, forest, - guard, } } - /// Marks this snapshot as superseded by a newer published generation; see - /// [`SnapshotGuard::mark_superseded`]. - pub(in crate::state) fn mark_superseded(&self) { - self.guard.mark_superseded(); - } - /// Returns the latest block number. pub(in crate::state) fn latest_block_num(&self) -> BlockNumber { self.blockchain @@ -291,13 +219,20 @@ mod tests { let status = published.advance(tip); assert_eq!(status.prune_tip, BlockNumber::from(97)); assert_eq!(status.oldest_pinned, Some(BlockNumber::from(97))); + assert_eq!(published.live(), 3); + // Recording generation 98 superseded generation 97. + assert!(status.oldest_superseded_for.is_some()); // Dropping a middle generation leaves the oldest unchanged. drop(gen_98); assert_eq!(published.advance(tip).prune_tip, BlockNumber::from(97)); drop(gen_97); - assert_eq!(published.advance(tip).prune_tip, BlockNumber::from(99)); + let status = published.advance(tip); + assert_eq!(status.prune_tip, BlockNumber::from(99)); + assert_eq!(published.live(), 1); + // Generation 99 is the latest generation and is not superseded. + assert!(status.oldest_superseded_for.is_none()); // A pinned generation never advances pruning past the tip. assert_eq!(published.advance(BlockNumber::from(98)).prune_tip, BlockNumber::from(98)); @@ -320,6 +255,8 @@ mod tests { let status = published.advance(tip); assert_eq!(status.prune_tip, BlockNumber::from(1)); assert_eq!(status.oldest_pinned, Some(BlockNumber::from(1))); + // No successor generation was recorded, so the leaked generation is not superseded. + assert!(status.oldest_superseded_for.is_none()); // Once the tip advances past the cap it no longer holds pruning back, but is still reported // as the oldest pinned generation for as long as it is pinned. @@ -336,6 +273,8 @@ mod tests { let status = published.advance(tip); assert_eq!(status.prune_tip, recent_height); assert_eq!(status.oldest_pinned, Some(BlockNumber::from(1))); + // Recording the newer generation superseded the leaked generation. + assert!(status.oldest_superseded_for.is_some()); drop(leaked); let status = published.advance(tip); diff --git a/crates/store/src/state/writer/worker.rs b/crates/store/src/state/writer/worker.rs index 7666ef3b9..11c9c0cf4 100644 --- a/crates/store/src/state/writer/worker.rs +++ b/crates/store/src/state/writer/worker.rs @@ -1,6 +1,5 @@ //! The write worker: single-task owner of the store's mutable trees. -use std::sync::atomic::{AtomicUsize, Ordering}; use std::sync::{Arc, Once}; use arc_swap::ArcSwap; @@ -38,13 +37,7 @@ use crate::db::{Db, NoteRecord}; use crate::errors::{ApplyBlockError, InvalidBlockError}; use crate::state::block_lifecycle::{BlockLifecycle, lifecycle_events_enabled}; use crate::state::loader::TreeStorage; -use crate::state::view::{ - PublishedGenerations, - SNAPSHOT_LAG_WARN_THRESHOLD, - SNAPSHOTS_LIVE_WARN_THRESHOLD, - SnapshotGuard, - StateSnapshot, -}; +use crate::state::view::{PublishedGenerations, StateSnapshot}; use crate::state::{BlockCache, BlockNotification}; use crate::{COMPONENT, HistoricalError, LOG_TARGET}; @@ -72,8 +65,6 @@ pub(in crate::state) struct WriteWorker { blockchain: Blockchain, /// The mutable account state forest owned by this writer. forest: AccountStateForest, - /// Shared counter of live snapshot generations, for observability. - snapshots_live: Arc, /// Writer-local log of published generations; its oldest still-pinned height feeds the /// snapshot-aware history-pruning tip. published_generations: PublishedGenerations, @@ -111,7 +102,6 @@ impl WriteWorker { account_tree: AccountTreeWithHistory, blockchain: Blockchain, forest: AccountStateForest, - snapshots_live: Arc, apply_block_thread_priority: bool, ) -> Self { // Seed the generation log with the initial snapshot so its readers hold back pruning @@ -139,7 +129,6 @@ impl WriteWorker { account_tree, blockchain, forest, - snapshots_live, published_generations, apply_pool, } @@ -237,17 +226,13 @@ impl WriteWorker { let snapshot_lag = generations .oldest_pinned .map_or(0, |oldest| block_num.as_u32() - oldest.as_u32()); - miden_span_record!(snapshots.lag_blocks = snapshot_lag); - if snapshot_lag > SNAPSHOT_LAG_WARN_THRESHOLD { - tracing::warn!( - target: COMPONENT, - block_num = block_num.as_u32(), - prune_tip = generations.prune_tip.as_u32(), - snapshots.lag_blocks = snapshot_lag, - "a state snapshot is pinned far behind the chain tip; a slow or leaked reader is \ - retaining RocksDB garbage and holding back history pruning", - ); - } + let oldest_superseded_for_ms = generations + .oldest_superseded_for + .map_or(0, |superseded| u64::try_from(superseded.as_millis()).unwrap_or(u64::MAX)); + miden_span_record!( + snapshots.lag_blocks = snapshot_lag, + snapshots.oldest_superseded_for_ms = oldest_superseded_for_ms + ); let prune_tip = generations.prune_tip; let resolved_note_ids = self .db @@ -272,13 +257,13 @@ impl WriteWorker { ); // Atomically publish the new state. Readers that call `snapshot()` after this point will - // see the updated state. Readers holding the old snapshot continue unaffected, but are on - // the clock: a superseded generation held too long is reported on release. + // see the updated state. Readers that hold the old snapshot are not affected. `record` + // marks the old generation as superseded. The `snapshots.oldest_superseded_for_ms` span + // field reports how long that generation stays pinned after supersession. self.published_generations.record(block_num, &snapshot); - self.latest_snapshot.swap(snapshot).mark_superseded(); + self.latest_snapshot.swap(snapshot); - let snapshots_live = self.check_live_snapshots(block_num); - miden_span_record!(snapshots.live = snapshots_live); + miden_span_record!(snapshots.live = self.published_generations.live()); // Push to cache and notify replica subscribers. self.block_cache @@ -297,24 +282,6 @@ impl WriteWorker { Ok(()) } - /// Returns the number of live snapshot generations, warning when slow readers are pinning too - /// many old generations in memory. - /// - /// The count is returned rather than recorded here because `miden_span_record!` must be used - /// within a `#[miden_instrument]` function. - fn check_live_snapshots(&self, block_num: BlockNumber) -> u64 { - let snapshots_live = self.snapshots_live.load(Ordering::Relaxed) as u64; - if snapshots_live > SNAPSHOTS_LIVE_WARN_THRESHOLD { - warn!( - target: COMPONENT, - "too many live state snapshots; slow readers are pinning old generations", - block.number = block_num, - snapshots.live = snapshots_live - ); - } - snapshots_live - } - /// Computes the note records and all tree and forest mutations for a block, without mutating /// any state, and serializes the signed block. /// @@ -420,7 +387,6 @@ impl WriteWorker { self.blockchain.clone(), self.account_tree.reader(), self.forest.reader().expect("forest snapshot creation should not fail"), - SnapshotGuard::new(Arc::clone(&self.snapshots_live), block_num), )) }) } diff --git a/crates/tracing/src/attribute.rs b/crates/tracing/src/attribute.rs index 62031cda0..fe1154db1 100644 --- a/crates/tracing/src/attribute.rs +++ b/crates/tracing/src/attribute.rs @@ -76,10 +76,9 @@ const NUMBER_FIELD_NAMES: &[&str] = &[ "retry.delay_ms", "shutdown.grace_period_ms", "snapshot.block_num", - "snapshot.lifetime_ms", - "snapshot.superseded_for_ms", "snapshots.lag_blocks", "snapshots.live", + "snapshots.oldest_superseded_for_ms", "subscription.idle_ms", "subscription.stall_timeout_ms", "sync.block_gap", From f9499836939030ed9dc89fc1400f32015a82f5e4 Mon Sep 17 00:00:00 2001 From: sergerad Date: Tue, 1 Sep 2026 13:27:35 +1200 Subject: [PATCH 6/7] RM span comment --- crates/store/src/state/view/mod.rs | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/crates/store/src/state/view/mod.rs b/crates/store/src/state/view/mod.rs index 2022a02d8..6c9d7721e 100644 --- a/crates/store/src/state/view/mod.rs +++ b/crates/store/src/state/view/mod.rs @@ -45,11 +45,7 @@ pub use transaction_inputs::TransactionInputs; /// /// Obtained from [`State::view`]; create one per request and drop it when the request completes. /// Holding a view pins a snapshot generation (and thereby the `RocksDB` snapshots backing the -/// trees), so it must not be stored in long-lived structs. The block writer records the span -/// fields `snapshots.lag_blocks`, `snapshots.oldest_superseded_for_ms`, and `snapshots.live` on -/// each applied block. Those fields show that some reader pins an old generation. Views are -/// acquired inside instrumented request spans, so the span durations bound the hold time and -/// identify the reader. +/// trees), so it must not be stored in long-lived structs. /// /// Reads that are technically not block-scoped (e.g. content-addressed note scripts) also live /// here so that every read path flows through a single, consistently-scoped type. From cfd71d3e5afeca8a1eb92d1da36369255abb84b8 Mon Sep 17 00:00:00 2001 From: sergerad Date: Tue, 1 Sep 2026 14:10:18 +1200 Subject: [PATCH 7/7] Fix comments --- crates/store/src/state/view/mod.rs | 3 +-- crates/store/src/state/view/snapshot.rs | 28 +++++++++++++------------ crates/store/src/state/writer/worker.rs | 4 +--- 3 files changed, 17 insertions(+), 18 deletions(-) diff --git a/crates/store/src/state/view/mod.rs b/crates/store/src/state/view/mod.rs index 6c9d7721e..a86c6d661 100644 --- a/crates/store/src/state/view/mod.rs +++ b/crates/store/src/state/view/mod.rs @@ -88,8 +88,7 @@ impl State { /// /// Work in the closure should be kept to low-complexity compute over the view, ideally with no /// I/O and no other `.await` points. Anything slower holds the pinned snapshot, and therefore - /// its underlying `RocksDB` snapshot, for as long as it runs. The block writer's per-block - /// snapshot span fields expose generations that stay pinned too long. + /// its underlying `RocksDB` snapshot, for as long as it runs. pub async fn with_view(&self, f: impl AsyncFnOnce(&StateView) -> R) -> R { let view = self.view(); f(&view).await diff --git a/crates/store/src/state/view/snapshot.rs b/crates/store/src/state/view/snapshot.rs index c9ead7b8a..87e05adc3 100644 --- a/crates/store/src/state/view/snapshot.rs +++ b/crates/store/src/state/view/snapshot.rs @@ -4,8 +4,7 @@ //! by the block writer after each committed block. The writer remembers each published generation //! in [`PublishedGenerations`]. The oldest still-pinned height feeds snapshot-aware history //! pruning, since SQLite reads have no point-in-time protection equivalent to the `RocksDB` -//! snapshots backing the trees. The same log supplies the per-block snapshot span fields that -//! expose slow or leaked readers. +//! snapshots backing the trees. //! //! Everything here operates on whole generations. Readers acquire a snapshot through //! [`StateView`](super::StateView), the request-scoped handle. @@ -26,14 +25,16 @@ use crate::account_state_forest::{ use crate::accounts::AccountTreeWithHistory; use crate::state::loader::TreeStorageReader; -/// Upper bound on how far the snapshot-aware pruning tip may lag the chain tip. +/// Upper bound, in blocks, on how far history pruning may trail the chain tip. /// -/// History pruning keys off the oldest live snapshot generation (see -/// [`PublishedGenerations::advance`]), so a leaked or pathologically slow reader would -/// otherwise stall pruning indefinitely. Beyond this many blocks of lag the writer prunes anyway -/// and accepts the historical-read race for that reader. The `snapshots.lag_blocks` span field -/// reports the lag on each applied block (see [`GenerationsStatus::oldest_pinned`]). The cap is -/// one full retention window, so worst-case retained history is bounded at twice the window. +/// Pruning normally waits for the oldest live snapshot generation, so SQLite history that a +/// pinned generation can still read is not deleted (see [`PublishedGenerations::advance`]). +/// Without a bound, one leaked reader would block pruning forever. Once a generation falls more +/// than this many blocks behind the tip, pruning stops waiting for it. Rows inside that reader's +/// retention window may then be deleted while it still holds the generation, so its historical +/// SQLite reads may observe missing data. Its tree reads are unaffected: the generation still +/// pins the `RocksDB` snapshots backing the trees. The cap equals one retention window, so +/// retained history never exceeds two windows. const SNAPSHOT_PRUNE_LAG_CAP: u32 = HISTORICAL_BLOCK_RETENTION; // PUBLISHED GENERATIONS @@ -61,10 +62,11 @@ struct Generation { /// The time when a successor generation was published. `None` while this is the latest /// generation. /// - /// [`PublishedGenerations::record`] sets this field on the previous back entry. Reader - /// behaviour is measured from supersession, not from publication: the published pointer - /// always pins the latest generation, so time spent as the latest generation gives no - /// information about readers. + /// [`PublishedGenerations::record`] sets this field on the previous back entry. A + /// generation's age is measured from this point rather than from its publication, because + /// the writer itself keeps the latest generation alive through the published pointer: on an + /// idle chain the latest generation can stay alive for hours with no reader holding it. Only + /// time spent alive after a successor exists is evidence that a reader holds the generation. superseded_at: Option, pinned: Weak, } diff --git a/crates/store/src/state/writer/worker.rs b/crates/store/src/state/writer/worker.rs index 11c9c0cf4..92296de30 100644 --- a/crates/store/src/state/writer/worker.rs +++ b/crates/store/src/state/writer/worker.rs @@ -257,9 +257,7 @@ impl WriteWorker { ); // Atomically publish the new state. Readers that call `snapshot()` after this point will - // see the updated state. Readers that hold the old snapshot are not affected. `record` - // marks the old generation as superseded. The `snapshots.oldest_superseded_for_ms` span - // field reports how long that generation stays pinned after supersession. + // see the updated state. Readers that hold the old snapshot are not affected. self.published_generations.record(block_num, &snapshot); self.latest_snapshot.swap(snapshot);