From d20d6320609febb299b34afb6f82d972cb202369 Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 7 Aug 2026 12:42:19 +1200 Subject: [PATCH 1/4] 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/4] 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/4] 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/4] 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.