From 7398bd5a4ee3f72b5d507b2dd6932717cd584923 Mon Sep 17 00:00:00 2001 From: "rbitcoin-grok[bot]" Date: Wed, 9 Sep 2026 12:56:50 -0700 Subject: [PATCH 1/3] test(ibd): pin never-written perf tokens as absent X-01 dead-meter cut: shipped ibd: perf / sizes still emit recon/wire/ resolve, parent_io, miss_p, cold_idx, recent_pub, tip_gc, pstore, and always-zero recent occupancy even though those counters are never incremented. Fail until sample/format drop them. Live load/script/write stage tokens must stay. --- crates/rbitcoin-net/src/ibd/perf_log.rs | 82 +++++++++++++++++++++++++ 1 file changed, 82 insertions(+) diff --git a/crates/rbitcoin-net/src/ibd/perf_log.rs b/crates/rbitcoin-net/src/ibd/perf_log.rs index 320a7a126..6a2e4cd99 100644 --- a/crates/rbitcoin-net/src/ibd/perf_log.rs +++ b/crates/rbitcoin-net/src/ibd/perf_log.rs @@ -2116,6 +2116,88 @@ mod tests { } } + #[test] + fn format_lines_omit_never_written_inventory_tokens() { + let mut s = IbdPerfSample::default(); + s.phase_blks = 8; + s.load_ms = 30; + s.connect_ms = 8; + s.script_ms = 20; + s.write.class_a_ms = 12; + s.write.ensure_ms = 3; + s.write.class_c_ms = 4; + s.recon_ms = 99; + s.wire_ms = 88; + s.resolve_ms = 77; + s.recon_ns = 10_000_000; + s.wire_ns = 9_000_000; + s.resolve_ns = 8_000_000; + s.load_parent_tx_reads = 12; + s.load_creates = 50; + s.load_missing_parents = 3; + s.load_cache_put_ms = 2; + s.load_hdr_ms = 5; + s.load_decode_ms = 6; + s.load_edge_same = 10; + s.load_edge_fk = 5; + s.load_edge_cb = 1; + s.load_cold_idx_ms = 400; + s.load_cold_idx_n = 2; + s.load_cold_decode_ms = 10; + s.load_pin_new_meta_ms = 14; + s.write.recent_pub_ms = 6; + s.write.recent_pub_ns = 6_000_000; + s.write.cache_tip_ms = 5; + s.write.cache_tip_ns = 5_000_000; + s.spend_idx = 2; + s.spend_skip = 1; + s.ann_pread = 4; + s.asm_prev_batch_ms = 2000; + s.asm_prev_same_ms = 50; + s.asm_prev_cold_ms = 250; + s.asm_prev_fk_ms = 10; + s.owned.pstore_weak = 20_000; + s.owned.pstore_live = 8_000; + s.owned.pstore_bytes = 16 * 1024 * 1024; + s.owned.recent_heights = 12; + s.owned.recent_keys = 400; + let info = format_info(&s); + let dbg = format_debug(&s); + let sizes = format_sizes(&s); + assert!(info.starts_with("ibd: perf "), "{info}"); + assert!(info.contains("load="), "{info}"); + assert!(info.contains("script="), "{info}"); + assert!(info.contains("write="), "{info}"); + assert!(info.contains("class_a="), "{info}"); + assert!(dbg.contains("us/blk load="), "{dbg}"); + assert!(dbg.contains("script="), "{dbg}"); + assert!(dbg.contains("write="), "{dbg}"); + for line in [&info, &dbg] { + assert!(!line.contains("recon_ms="), "{line}"); + assert!(!line.contains("recon_us="), "{line}"); + assert!(!line.contains("wire_ms="), "{line}"); + assert!(!line.contains("wire_us="), "{line}"); + assert!(!line.contains("resolve_ms="), "{line}"); + assert!(!line.contains("resolve_us="), "{line}"); + assert!(!line.contains("parent_io="), "{line}"); + assert!(!line.contains("recent_pub="), "{line}"); + assert!(!line.contains("unpin"), "{line}"); + assert!(!line.contains("miss_p="), "{line}"); + assert!(!line.contains("cold_idx="), "{line}"); + assert!(!line.contains("cold_dec="), "{line}"); + assert!(!line.contains("edges same="), "{line}"); + assert!(!line.contains("tip_gc="), "{line}"); + assert!(!line.contains("spend_mix"), "{line}"); + assert!(!line.contains(" pread="), "{line}"); + } + assert!(!dbg.contains("creates="), "{dbg}"); + assert!(!sizes.contains("pstore"), "{sizes}"); + assert!( + !sizes.contains("recent="), + "always-zero recent= occupancy: {sizes}" + ); + } + #[test] fn format_info_has_stable_tokens() { let mut s = IbdPerfSample::default(); From 98bba3d74e3628cd6b8aec89c252407c56e6dd9b Mon Sep 17 00:00:00 2001 From: "rbitcoin-grok[bot]" Date: Wed, 9 Sep 2026 13:09:37 -0700 Subject: [PATCH 2/3] perf(ibd): drop never-written confirm/query/store meters Delete statics, Sample fields, and format tokens with no production fetch_add: confirm_load CREATES/edges/cold_idx/decode, reconstruct/ resolve/unpin/cache_tip/recent_pub, HeadLookupStats, and always-zero pstore/recent occupancy. Keep live lookup/load/scripts/write stage timers and last-pin / last-write snapshots. write= no longer includes always-zero tip_gc/recent_pub. --- CHANGELOG.md | 7 + OPERATOR.md | 2 +- .../src/block/structure_rule_tests.rs | 2 +- crates/rbitcoin-consensus/src/lib.rs | 103 +---- crates/rbitcoin-net/src/chain.rs | 7 - crates/rbitcoin-net/src/ibd/confirm/mod.rs | 4 +- crates/rbitcoin-net/src/ibd/perf_log.rs | 413 +++--------------- crates/rbitcoin-query/src/confirm_load.rs | 17 - crates/rbitcoin-query/src/in_flight.rs | 4 +- crates/rbitcoin-query/src/lib.rs | 115 +---- crates/rbitcoin-query/src/query_tests.rs | 14 +- crates/rbitcoin-store/src/lib.rs | 6 +- crates/rbitcoin-store/src/segmented_head.rs | 82 ---- docs/ibd-memory.md | 2 +- 14 files changed, 101 insertions(+), 677 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index babf104b4..0165c4b46 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -24,6 +24,13 @@ before 1.0). - **Workspace version 0.6.99:** in-tree toward 0.7.0. Published GitHub Releases remain 0.6.0; `v0.6.x` is the patch branch. +- **`ibd: perf` / `ibd: sizes` drop never-written meters:** DEBUG no longer + prints `recon`/`wire`/`resolve`, `parent_io`, `miss_p`, `cold_idx`, + `tip_gc`, `recent_pub`, annotate `pread=`, `spend_mix i=/skip=`, + `pstore`, or always-zero heap `recent=` occupancy. Live lookup / load / + scripts / write stage tokens stay. `write=` is Class A + ensure + + structural + class_c + SH + spend + tweaks + pins + head_sub + + drain_join + dequeue. ## [0.6.0] — 2026-09-08 diff --git a/OPERATOR.md b/OPERATOR.md index 7977d85bf..64ef1ea92 100644 --- a/OPERATOR.md +++ b/OPERATOR.md @@ -323,7 +323,7 @@ Requires **tip mode** (`node: catch-up complete … tip tracking`). During IBD u | `ibd: progress` | INFO | Tip rate, `loadq`/`scriptq`/`writeq`, `txs=` (Class A / `tx.idx` count), horizon, tip ETA, **`bq soft=n/win RAM=`** (in-RAM body queue; soft densify: under ~100 MiB free ahead, over that only ~1 min confirm window, at/over 1 GiB assign-stop holes within that window and not past fetched_hi) | | `ibd: perf` | DEBUG | Inflight + **`bq soft= RAM=`**; **`load=`** is pin+assemble only. **`load_thr pack/stamp/pin/asm/prune`** is the load OS thread. **`stamp=`** nests **`pack=`** (plan HashMap) vs **`head=`** (leftover TipOnly; IBD skeleton keeps this ~0). **`script=`** is verify ns (`jobs=` / `skip=`); recv/send are wait. **`pin_txid=`** is skeleton hits vs leftover `tx.head` | | `ibd: sizes` | DEBUG | RSS + work path + **`bq soft=` / `RAM=`** + **conf_plans** + confirm pipe | -| `ibd: perf_dbg` | DEBUG | µs/blk load/write, pin/edge detail, **plan_batch** (`us/pin_txid` vs `probe/idx/body us/key`) + **class_a commit** | +| `ibd: perf_dbg` | DEBUG | µs/blk load/write, pin detail, **plan_batch** (`us/pin_txid` vs `probe/idx/body us/key`) + **class_a commit** | Default INFO is `ibd: progress` only. `--log-level debug` adds perf / sizes / perf_dbg from the same sample. Ghost columns from deleted paths (wave-fill stubs, Direct SH head RMW) are omitted from both formatters. Pipeline roles: [`docs/concurrency.md`](docs/concurrency.md). Head files: [`docs/heads.md`](docs/heads.md). diff --git a/crates/rbitcoin-consensus/src/block/structure_rule_tests.rs b/crates/rbitcoin-consensus/src/block/structure_rule_tests.rs index 4fd261053..05cce1c9e 100644 --- a/crates/rbitcoin-consensus/src/block/structure_rule_tests.rs +++ b/crates/rbitcoin-consensus/src/block/structure_rule_tests.rs @@ -1334,7 +1334,7 @@ fn assemble_pending_creates_is_txid_map_and_meters_flush() { .expect("coinbase-only assemble"); assert_eq!(creates.len(), 1, "one create fk per tx, not per vout"); assert_eq!(creates.get(&tids[0]), Some(&Fk(1))); - let (in_n, _bns, batch_n, _sns, same_n, ..) = + let (in_n, batch_n, same_n, ..) = confirm_phase_stats::sample_assemble_prevout_detail_and_reset(); assert_eq!(in_n, 0, "coinbase has no prevouts"); assert_eq!(batch_n, 0); diff --git a/crates/rbitcoin-consensus/src/lib.rs b/crates/rbitcoin-consensus/src/lib.rs index 42e5677e0..13681642e 100644 --- a/crates/rbitcoin-consensus/src/lib.rs +++ b/crates/rbitcoin-consensus/src/lib.rs @@ -92,10 +92,6 @@ use rbitcoin_store::HeaderRecord; /// IBD diagnostics: wall time spent in each phase (nanoseconds; reset by the sampler). pub mod confirm_phase_stats { use std::sync::atomic::{AtomicU64, Ordering}; - /// Total reconstruct-ish wall (wire rebuild; historical total). - pub static RECONSTRUCT_NS: AtomicU64 = AtomicU64::new(0); - /// Full wire `Block` rebuild from Class A rows. - pub static RECONSTRUCT_WIRE_NS: AtomicU64 = AtomicU64::new(0); /// Optimistic assemble (prevout content + jobs; no durable spentness). pub static CONNECT_NS: AtomicU64 = AtomicU64::new(0); pub static SCRIPT_NS: AtomicU64 = AtomicU64::new(0); @@ -135,12 +131,6 @@ pub mod confirm_phase_stats { pub static TWEAK_NS: AtomicU64 = AtomicU64::new(0); /// Write-stage denserels/abs ensure after Class A (fill planned + ensure spends). pub static ENSURE_LAYOUT_NS: AtomicU64 = AtomicU64::new(0); - /// Write-stage RecentCreates note+expire+one snapshot publish. - pub static WRITE_RECENT_NS: AtomicU64 = AtomicU64::new(0); - /// `tx_body_range_batch` inside that publish. - pub static WRITE_RECENT_IDX_NS: AtomicU64 = AtomicU64::new(0); - /// `publish_if_dirty` clone inside that publish. - pub static WRITE_RECENT_CLONE_NS: AtomicU64 = AtomicU64::new(0); /// `class_c_commit` wall minus tables (`flush` / SH join). pub static WRITE_CLASS_C_JOIN_NS: AtomicU64 = AtomicU64::new(0); /// Residual wait on `head_insert_queued` join after Class C / annotate. @@ -164,15 +154,9 @@ pub mod confirm_phase_stats { pub static ASM_JOB_NS: AtomicU64 = AtomicU64::new(0); /// Non-coinbase inputs resolved in `resolve_prevout` (for us/in). pub static ASM_IN_N: AtomicU64 = AtomicU64::new(0); - /// Prevout path splits (ns + counts; sum of path ns ≈ ASM_PREVOUT_NS). - pub static ASM_PREV_BATCH_NS: AtomicU64 = AtomicU64::new(0); pub static ASM_PREV_BATCH_N: AtomicU64 = AtomicU64::new(0); - pub static ASM_PREV_SAME_NS: AtomicU64 = AtomicU64::new(0); pub static ASM_PREV_SAME_N: AtomicU64 = AtomicU64::new(0); - pub static ASM_PREV_COLD_NS: AtomicU64 = AtomicU64::new(0); pub static ASM_PREV_COLD_N: AtomicU64 = AtomicU64::new(0); - /// Time in `tx_fk_by_txid` / durable head lookup on cold prevout path. - pub static ASM_PREV_FK_NS: AtomicU64 = AtomicU64::new(0); /// Cold success with **no** `prev_fk_hint` (thin + pending + head miss at assemble). pub static ASM_PREV_COLD_NULL_FK_N: AtomicU64 = AtomicU64::new(0); /// Cold success: had fk, batch pin miss (pin did not cover parent/vout). @@ -189,22 +173,14 @@ pub mod confirm_phase_stats { /// Annotate edges via abs pin denserels (pure-write known meta). /// Historical name: formerly also counted ranged body walks (removed on Direct write). pub static SPEND_ANNOTATE_RANGED: AtomicU64 = AtomicU64::new(0); - /// Legacy cold idx annotate path (must stay 0 on Direct IBD after abs-only write). - pub static SPEND_ANNOTATE_IDX: AtomicU64 = AtomicU64::new(0); - /// Spends skipped (null create_fk or null spend_fk). - pub static SPEND_ANNOTATE_SKIP: AtomicU64 = AtomicU64::new(0); /// Pure-write annotate wall (ns) / edge count (backend is uring or pwrite). pub static SPEND_ANN_NS: AtomicU64 = AtomicU64::new(0); pub static SPEND_ANN_N: AtomicU64 = AtomicU64::new(0); /// Edges annotated without body pread (should equal all annotate edges). pub static SPEND_ANN_PREAD_SKIP: AtomicU64 = AtomicU64::new(0); - /// Body preads on annotate (must stay 0 on pure-write write path). - pub static SPEND_ANN_PREAD: AtomicU64 = AtomicU64::new(0); /// Structural spent meta bulk read wall (ns) / peek count. pub static SPEND_META_NS: AtomicU64 = AtomicU64::new(0); pub static SPEND_META_N: AtomicU64 = AtomicU64::new(0); - /// Header + body-fk resolve for the batch. - pub static RESOLVE_NS: AtomicU64 = AtomicU64::new(0); /// Prep pre-assemble wall on the prep/load thread. /// /// Wire path: structure + plan Class A + pin parents (stops before assemble). @@ -220,10 +196,6 @@ pub mod confirm_phase_stats { pub static PREP_PREPARE_NS: AtomicU64 = AtomicU64::new(0); /// Wire load sub: filter need + plan batch + meta/tx_fks wiring (not pin). pub static PREP_FILTER_PLAN_NS: AtomicU64 = AtomicU64::new(0); - /// Unpin spent outs from ConfirmParentCache after Class C. - pub static UNPIN_NS: AtomicU64 = AtomicU64::new(0); - /// `advance_parent_cache_tip` (drop bodies / GC parents). - pub static CACHE_TIP_NS: AtomicU64 = AtomicU64::new(0); pub static BLOCKS: AtomicU64 = AtomicU64::new(0); static LAST_WRITE_N: AtomicU64 = AtomicU64::new(0); @@ -322,21 +294,6 @@ pub mod confirm_phase_stats { ) } - /// Sample and reset write-stage RecentCreates publish wall. - #[inline] - pub fn sample_write_recent_and_reset() -> u64 { - WRITE_RECENT_NS.swap(0, Ordering::Relaxed) - } - - /// `(idx, clone)` parts of RecentCreates publish. - #[inline] - pub fn sample_write_recent_parts_and_reset() -> (u64, u64) { - ( - WRITE_RECENT_IDX_NS.swap(0, Ordering::Relaxed), - WRITE_RECENT_CLONE_NS.swap(0, Ordering::Relaxed), - ) - } - /// `(drain_join, dequeue)` residual write walls. #[inline] pub fn sample_write_residuals_and_reset() -> (u64, u64) { @@ -388,20 +345,14 @@ pub mod confirm_phase_stats { ) } - /// Prevout path detail: `(in_n, batch_ns, batch_n, same_ns, same_n, - /// cold_ns, cold_n, fk_ns)`. + /// Prevout path counts: `(in_n, batch_n, same_n, cold_n)`. #[inline] - #[allow(clippy::type_complexity)] - pub fn sample_assemble_prevout_detail_and_reset() -> (u64, u64, u64, u64, u64, u64, u64, u64) { + pub fn sample_assemble_prevout_detail_and_reset() -> (u64, u64, u64, u64) { ( ASM_IN_N.swap(0, Ordering::Relaxed), - ASM_PREV_BATCH_NS.swap(0, Ordering::Relaxed), ASM_PREV_BATCH_N.swap(0, Ordering::Relaxed), - ASM_PREV_SAME_NS.swap(0, Ordering::Relaxed), ASM_PREV_SAME_N.swap(0, Ordering::Relaxed), - ASM_PREV_COLD_NS.swap(0, Ordering::Relaxed), ASM_PREV_COLD_N.swap(0, Ordering::Relaxed), - ASM_PREV_FK_NS.swap(0, Ordering::Relaxed), ) } @@ -505,14 +456,12 @@ pub mod confirm_phase_stats { /// Sample and reset all confirm phases. /// /// Returns - /// `(recon, wire, connect, script, class_c, strong, scripthash, tip, - /// utxo_apply, blocks, resolve, load, unpin, cache_tip, - /// spend_ranged, spend_idx, spend_skip, structural, structural_spent, - /// structural_create_h, structural_bip68)`. + /// `(connect, script, class_c, strong, scripthash, tip, utxo_apply, blocks, + /// load, spend_ranged, structural, structural_spent, structural_create_h, + /// structural_bip68)`. /// `class_c` is **strong+tip tables only** (not SH join wall; SH is /// `scripthash`). `strong` / `scripthash` / `tip` come from /// [`rbitcoin_query::class_c_phase_stats`]. - /// `recon` prefers wire sub-timer, else legacy total. /// `connect` is **load assemble**, not write structural — see `structural`. #[allow(clippy::type_complexity)] pub fn sample_and_reset() -> ( @@ -530,21 +479,9 @@ pub mod confirm_phase_stats { u64, u64, u64, - u64, - u64, - u64, - u64, - u64, - u64, - u64, ) { let (strong, sh, tip) = rbitcoin_query::class_c_phase_stats::sample_and_reset(); - let wire = RECONSTRUCT_WIRE_NS.swap(0, Ordering::Relaxed); - let recon_total = RECONSTRUCT_NS.swap(0, Ordering::Relaxed); - let recon = if wire > 0 { wire } else { recon_total }; ( - recon, - wire, CONNECT_NS.swap(0, Ordering::Relaxed), SCRIPT_NS.swap(0, Ordering::Relaxed), CLASS_C_NS.swap(0, Ordering::Relaxed), @@ -553,13 +490,8 @@ pub mod confirm_phase_stats { tip, UTXO_APPLY_NS.swap(0, Ordering::Relaxed), BLOCKS.swap(0, Ordering::Relaxed), - RESOLVE_NS.swap(0, Ordering::Relaxed), LOAD_NS.swap(0, Ordering::Relaxed), - UNPIN_NS.swap(0, Ordering::Relaxed), - CACHE_TIP_NS.swap(0, Ordering::Relaxed), SPEND_ANNOTATE_RANGED.swap(0, Ordering::Relaxed), - SPEND_ANNOTATE_IDX.swap(0, Ordering::Relaxed), - SPEND_ANNOTATE_SKIP.swap(0, Ordering::Relaxed), STRUCTURAL_NS.swap(0, Ordering::Relaxed), STRUCTURAL_SPENT_NS.swap(0, Ordering::Relaxed), STRUCTURAL_CREATE_H_NS.swap(0, Ordering::Relaxed), @@ -576,14 +508,13 @@ pub mod confirm_phase_stats { ) } - /// Pure-write annotate: (ann_ns, ann_n, pread_skip, pread). + /// Pure-write annotate: (ann_ns, ann_n, pread_skip). #[inline] - pub fn sample_spend_ann_and_reset() -> (u64, u64, u64, u64) { + pub fn sample_spend_ann_and_reset() -> (u64, u64, u64) { ( SPEND_ANN_NS.swap(0, Ordering::Relaxed), SPEND_ANN_N.swap(0, Ordering::Relaxed), SPEND_ANN_PREAD_SKIP.swap(0, Ordering::Relaxed), - SPEND_ANN_PREAD.swap(0, Ordering::Relaxed), ) } @@ -914,8 +845,6 @@ mod coverage_tests { WRITE_HEAD_SUB_NS.store(33, Ordering::Relaxed); assert_eq!(sample_write_pins_and_reset(), (11, 22, 33)); assert_eq!(sample_write_pins_and_reset(), (0, 0, 0)); - RECONSTRUCT_NS.store(5, Ordering::Relaxed); - RECONSTRUCT_WIRE_NS.store(7, Ordering::Relaxed); CONNECT_NS.store(1, Ordering::Relaxed); SCRIPT_NS.store(1, Ordering::Relaxed); CLASS_C_NS.store(1, Ordering::Relaxed); @@ -923,20 +852,15 @@ mod coverage_tests { ENSURE_LAYOUT_NS.store(11, Ordering::Relaxed); UTXO_APPLY_NS.store(1, Ordering::Relaxed); BLOCKS.store(1, Ordering::Relaxed); - RESOLVE_NS.store(1, Ordering::Relaxed); LOAD_NS.store(1, Ordering::Relaxed); - UNPIN_NS.store(1, Ordering::Relaxed); - CACHE_TIP_NS.store(1, Ordering::Relaxed); SPEND_ANNOTATE_RANGED.store(1, Ordering::Relaxed); - SPEND_ANNOTATE_IDX.store(1, Ordering::Relaxed); - SPEND_ANNOTATE_SKIP.store(1, Ordering::Relaxed); STRUCTURAL_NS.store(1, Ordering::Relaxed); STRUCTURAL_SPENT_NS.store(1, Ordering::Relaxed); STRUCTURAL_CREATE_H_NS.store(1, Ordering::Relaxed); STRUCTURAL_BIP68_NS.store(1, Ordering::Relaxed); let s = sample_and_reset(); - assert_eq!(s.0, 7); // wire preferred over recon total - assert_eq!(s.1, 7); + assert_eq!(s.0, 1); + assert_eq!(s.1, 1); let (ca, en) = sample_class_a_ensure_and_reset(); assert_eq!((ca, en), (9, 11)); // Drain prep residual (other tests may have accrued), then set known values. @@ -957,17 +881,10 @@ mod coverage_tests { // I3 assemble prevout path detail. let _ = sample_assemble_prevout_detail_and_reset(); ASM_IN_N.store(100, Ordering::Relaxed); - ASM_PREV_BATCH_NS.store(1000, Ordering::Relaxed); ASM_PREV_BATCH_N.store(80, Ordering::Relaxed); - ASM_PREV_SAME_NS.store(50, Ordering::Relaxed); ASM_PREV_SAME_N.store(5, Ordering::Relaxed); - ASM_PREV_COLD_NS.store(300, Ordering::Relaxed); ASM_PREV_COLD_N.store(5, Ordering::Relaxed); - ASM_PREV_FK_NS.store(40, Ordering::Relaxed); - assert_eq!( - sample_assemble_prevout_detail_and_reset(), - (100, 1000, 80, 50, 5, 300, 5, 40) - ); + assert_eq!(sample_assemble_prevout_detail_and_reset(), (100, 80, 5, 5)); let _ = sample_assemble_cold_why_and_reset(); ASM_PREV_COLD_NULL_FK_N.store(1, Ordering::Relaxed); ASM_PREV_COLD_NOT_PIN_N.store(2, Ordering::Relaxed); diff --git a/crates/rbitcoin-net/src/chain.rs b/crates/rbitcoin-net/src/chain.rs index 1e6fe4cb3..e6e687480 100644 --- a/crates/rbitcoin-net/src/chain.rs +++ b/crates/rbitcoin-net/src/chain.rs @@ -2379,8 +2379,6 @@ pub fn format_tip_accept_sh_line(i: &TipAcceptShInput) -> String { /// Sample meters after tip accept and emit INFO `tip: accept …` (SH breakdown). fn log_tip_accept_sh(query: &Query, height: u32, n_tx: usize, wall_ns: u64, mp_strip_ns: u64) { let ( - _recon, - _wire, connect_ns, script_ns, _class_c_ns, @@ -2389,13 +2387,8 @@ fn log_tip_accept_sh(query: &Query, height: u32, n_tx: usize, wall_ns: u64, mp_s tip_ns, spend_ns, _blks, - _resolve, load_ns, - _unpin, - _cache_tip, _spend_ranged, - _spend_idx, - _spend_skip, structural_ns, _struct_spent, _struct_create_h, diff --git a/crates/rbitcoin-net/src/ibd/confirm/mod.rs b/crates/rbitcoin-net/src/ibd/confirm/mod.rs index f473319ba..ccba0309b 100644 --- a/crates/rbitcoin-net/src/ibd/confirm/mod.rs +++ b/crates/rbitcoin-net/src/ibd/confirm/mod.rs @@ -65,10 +65,10 @@ impl LoadAheadState { } } - /// Publish InFlight occupancy for `ibd: sizes`. IBD has no process pstore. + /// Publish InFlight occupancy for `ibd: sizes`. fn publish_mem_stats(&self) { let (layers, pins, if_bytes) = self.in_flight.size_snapshot(); - rbitcoin_query::process_mem_stats::note(layers, pins, if_bytes, 0, 0, 0); + rbitcoin_query::process_mem_stats::note(layers, pins, if_bytes); } fn pipeline_for( diff --git a/crates/rbitcoin-net/src/ibd/perf_log.rs b/crates/rbitcoin-net/src/ibd/perf_log.rs index 6a2e4cd99..ad5e7c5cc 100644 --- a/crates/rbitcoin-net/src/ibd/perf_log.rs +++ b/crates/rbitcoin-net/src/ibd/perf_log.rs @@ -33,8 +33,8 @@ //! `ibd-confirm`; excludes head-of-line wait for write handoff). `thr script work` //! is that same ns. Recv/send are wait. Publisher parks; it does not `wait_done` //! on steal workers. -//! - **write** = Class A + ensure + structural + class_c + spend + tweaks + tip GC -//! + `recent_pub=` / `pins=` / `head_sub=` / `drain_join=` / `dequeue=`. +//! - **write** = Class A + ensure + structural + class_c + spend + tweaks +//! + `pins=` / `head_sub=` / `drain_join=` / `dequeue=`. //! `other=` is write-thread work minus that inventory. //! //! **Inventory rule:** new work on lookup / load / scripts / write (or a sidecar @@ -58,8 +58,8 @@ use rbitcoin_query::ProcessOwnedSizes; /// Write-stage tokens that must sum to `write=` / [`write_stage_ms`]. /// /// Inventory: `class_a` + `ensure` + `struct` + `class_c` + `sh` + `spend` -/// + `tweaks` + `tip_gc` + `recent_pub` + `pins` + `head_sub` + `drain_join` -/// + `dequeue`. `other=` is write-thread work minus this inventory. +/// + `tweaks` + `pins` + `head_sub` + `drain_join` + `dequeue`. `other=` is +/// write-thread work minus this inventory. /// Subtimers (spent_sub, ann, class_a_sub, pins take/map) stay on the outer /// sample until a later nest. #[derive(Clone, Debug, Default)] @@ -85,12 +85,6 @@ pub(crate) struct WriteStageSample { /// Tip write-through `index_sp_tweaks_batch` (`tweaks=`) pub tweak_ms: u64, pub tweak_ns: u64, - /// `advance_parent_cache_tip` (`tip_gc=`) - pub cache_tip_ms: u64, - pub cache_tip_ns: u64, - /// RecentCreates note+expire+one snapshot (`recent_pub=`) - pub recent_pub_ms: u64, - pub recent_pub_ns: u64, /// Write-thread pin Arc copies: plan take + create-pin FkMap (`pins=`) pub pins_ms: u64, pub pins_ns: u64, @@ -118,8 +112,6 @@ impl WriteStageSample { .saturating_add(self.sh_ms) .saturating_add(self.utxo_ms) .saturating_add(self.tweak_ms) - .saturating_add(self.cache_tip_ms) - .saturating_add(self.recent_pub_ms) .saturating_add(self.pins_ms) .saturating_add(self.head_sub_ms) .saturating_add(self.class_c_join_ms) @@ -136,8 +128,6 @@ impl WriteStageSample { .saturating_add(self.sh_ns) .saturating_add(self.utxo_apply_ns) .saturating_add(self.tweak_ns) - .saturating_add(self.cache_tip_ns) - .saturating_add(self.recent_pub_ns) .saturating_add(self.pins_ns) .saturating_add(self.head_sub_ns) .saturating_add(self.class_c_join_ns) @@ -176,8 +166,6 @@ pub(crate) struct IbdPerfSample { pub live: Option<(u32, u32, u32, u64)>, pub phase_blks: u64, - pub recon_ms: u64, - pub wire_ms: u64, pub connect_ms: u64, pub script_ms: u64, /// Write-stage exclusive tokens (`write=` = [`WriteStageSample::stage_ms`]). @@ -185,9 +173,6 @@ pub(crate) struct IbdPerfSample { /// Ensure mix: residency/pin hits vs cold denserels body loads. pub ensure_res_hit: u64, pub ensure_cold_n: u64, - /// RecentCreates idx vs snapshot clone (`recent_idx=` / `recent_clone=`). - pub recent_idx_ms: u64, - pub recent_clone_ms: u64, /// `pins=` part: planned_fks clone + pin Arc vec before Class A. pub pins_take_ms: u64, /// `pins=` part: write_create_pins FkMap insert after Class A. @@ -199,23 +184,17 @@ pub(crate) struct IbdPerfSample { pub asm_job_ms: u64, /// Non-coinbase inputs resolved (us/in = prevout_ns / max(1, asm_in_n)). pub asm_in_n: u64, - /// Prevout path: batch pin hit ms / count. - pub asm_prev_batch_ms: u64, + /// Prevout path: batch pin hit count. pub asm_prev_batch_n: u64, - /// Prevout path: residency hit ms / count. - /// Prevout path: same-block ms / count. - pub asm_prev_same_ms: u64, + /// Prevout path: same-block count. pub asm_prev_same_n: u64, - /// Prevout path: cold Class A ms / count. - pub asm_prev_cold_ms: u64, + /// Prevout path: cold Class A count. pub asm_prev_cold_n: u64, /// N1: cold success reasons (sum ≈ asm_prev_cold_n). pub asm_cold_null_fk_n: u64, pub asm_cold_not_pin_n: u64, pub asm_cold_txid_mismatch_n: u64, pub asm_cold_vout_miss_n: u64, - /// Prevout path: durable txid→fk lookup ms. - pub asm_prev_fk_ms: u64, pub strong_ms: u64, /// Structural sub: durable spentness probes. pub structural_spent_ms: u64, @@ -232,19 +211,14 @@ pub(crate) struct IbdPerfSample { /// Structural sub: BIP68 + coin MTP. pub structural_bip68_ms: u64, pub spend_ranged: u64, - pub spend_idx: u64, - pub spend_skip: u64, /// Pure-write annotate wall ms / edge count. pub ann_ms: u64, pub ann_n: u64, /// Annotate edges without body pread (should equal annotate edges). pub ann_pread_skip: u64, - /// Annotate body preads (must stay 0 on pure-write path). - pub ann_pread: u64, /// Structural meta bulk read wall ms / peek count. pub meta_ms: u64, pub meta_n: u64, - pub resolve_ms: u64, pub load_ms: u64, /// Wire load residual (inside load/pre_asm, outside pin): Arc clone. pub prep_wire_arc_ms: u64, @@ -256,8 +230,6 @@ pub(crate) struct IbdPerfSample { pub prep_prepare_ms: u64, /// filter need + plan batch + tx_fks wiring. pub prep_filter_plan_ms: u64, - pub recon_ns: u64, - pub wire_ns: u64, pub connect_ns: u64, pub script_ns: u64, pub strong_ns: u64, @@ -265,7 +237,6 @@ pub(crate) struct IbdPerfSample { pub structural_spent_ns: u64, pub structural_create_h_ns: u64, pub structural_bip68_ns: u64, - pub resolve_ns: u64, pub load_ns: u64, pub sh_runs: usize, @@ -286,7 +257,6 @@ pub(crate) struct IbdPerfSample { pub load_win_ms: u64, pub load_blocks: u64, pub load_utxo_parents: u64, - pub load_creates: u64, pub load_parent_unique: u64, pub load_pin_cache_body: u64, /// Pin hits from pipeline pins (subset of pin_cache when residency filled). @@ -294,14 +264,11 @@ pub(crate) struct IbdPerfSample { pub load_pin_plan: u64, pub load_pin_new: u64, pub load_pin_body_ms: u64, - pub load_pin_new_meta_ms: u64, pub load_plan_pin_ms: u64, - /// Pin residual sub-walls (adopt / recent-outs / range-fill insert / contract / publish). - pub load_pin_adopt_ms: u64, + /// Pin residual sub-walls (recent-outs / range-fill insert / contract). pub load_pin_range_fill_ms: u64, pub load_pin_recent_outs_ms: u64, pub load_pin_contract_ms: u64, - pub load_pin_publish_ms: u64, pub load_cold_io_ms: u64, /// Cold denserels by plan body range (ms / create count). pub load_cold_range_ms: u64, @@ -309,15 +276,7 @@ pub(crate) struct IbdPerfSample { /// N2.0: body pread vs sparse denserels decode (ms; sum ≈ cold_range). pub load_cold_range_body_ms: u64, pub load_cold_range_decode_ms: u64, - /// Cold denserels by idx→body (ms / create count). - pub load_cold_idx_ms: u64, - pub load_cold_idx_n: u64, - pub load_cold_decode_ms: u64, - /// pipeline pins lock: write wait/hold ms, write count. - /// pipeline pins lock: read wait/hold ms, read count. pub load_body_tx_reads: u64, - pub load_parent_tx_reads: u64, - pub load_missing_parents: u64, pub load_ready_through: u32, pub cache_bodies: usize, pub cache_plans: usize, @@ -388,14 +347,8 @@ pub(crate) struct IbdPerfSample { pub plan_already: u64, pub plan_cold: u64, pub plan_same_batch: u64, - pub load_hdr_ms: u64, - pub load_decode_ms: u64, pub load_thin_ms: u64, pub load_parent_pin_ms: u64, - pub load_cache_put_ms: u64, - pub load_edge_same: u64, - pub load_edge_fk: u64, - pub load_edge_cb: u64, pub arch_ext_need: u64, pub arch_head_need: u64, @@ -489,15 +442,11 @@ impl Default for IbdPerfSample { dominant: "idle", live: None, phase_blks: 0, - recon_ms: 0, - wire_ms: 0, connect_ms: 0, script_ms: 0, write: WriteStageSample::default(), ensure_res_hit: 0, ensure_cold_n: 0, - recent_idx_ms: 0, - recent_clone_ms: 0, pins_take_ms: 0, pins_map_ms: 0, asm_prevout_ms: 0, @@ -505,17 +454,13 @@ impl Default for IbdPerfSample { asm_final_ms: 0, asm_job_ms: 0, asm_in_n: 0, - asm_prev_batch_ms: 0, asm_prev_batch_n: 0, - asm_prev_same_ms: 0, asm_prev_same_n: 0, - asm_prev_cold_ms: 0, asm_prev_cold_n: 0, asm_cold_null_fk_n: 0, asm_cold_not_pin_n: 0, asm_cold_txid_mismatch_n: 0, asm_cold_vout_miss_n: 0, - asm_prev_fk_ms: 0, strong_ms: 0, structural_spent_ms: 0, spent_abs_ms: 0, @@ -525,23 +470,17 @@ impl Default for IbdPerfSample { structural_create_h_ms: 0, structural_bip68_ms: 0, spend_ranged: 0, - spend_idx: 0, - spend_skip: 0, ann_ms: 0, ann_n: 0, ann_pread_skip: 0, - ann_pread: 0, meta_ms: 0, meta_n: 0, - resolve_ms: 0, load_ms: 0, prep_wire_arc_ms: 0, prep_struct_ms: 0, prep_header_ms: 0, prep_prepare_ms: 0, prep_filter_plan_ms: 0, - recon_ns: 0, - wire_ns: 0, connect_ns: 0, script_ns: 0, strong_ns: 0, @@ -549,7 +488,6 @@ impl Default for IbdPerfSample { structural_spent_ns: 0, structural_create_h_ns: 0, structural_bip68_ns: 0, - resolve_ns: 0, load_ns: 0, sh_runs: 0, wf_body_store: 0, @@ -564,30 +502,21 @@ impl Default for IbdPerfSample { load_win_ms: 0, load_blocks: 0, load_utxo_parents: 0, - load_creates: 0, load_parent_unique: 0, load_pin_cache_body: 0, load_pin_plan: 0, load_pin_new: 0, load_pin_body_ms: 0, - load_pin_new_meta_ms: 0, load_plan_pin_ms: 0, - load_pin_adopt_ms: 0, load_pin_range_fill_ms: 0, load_pin_recent_outs_ms: 0, load_pin_contract_ms: 0, - load_pin_publish_ms: 0, load_cold_io_ms: 0, load_cold_range_ms: 0, load_cold_range_n: 0, load_cold_range_body_ms: 0, load_cold_range_decode_ms: 0, - load_cold_idx_ms: 0, - load_cold_idx_n: 0, - load_cold_decode_ms: 0, load_body_tx_reads: 0, - load_parent_tx_reads: 0, - load_missing_parents: 0, load_ready_through: 0, cache_bodies: 0, cache_plans: 0, @@ -645,14 +574,8 @@ impl Default for IbdPerfSample { plan_already: 0, plan_cold: 0, plan_same_batch: 0, - load_hdr_ms: 0, - load_decode_ms: 0, load_thin_ms: 0, load_parent_pin_ms: 0, - load_cache_put_ms: 0, - load_edge_same: 0, - load_edge_fk: 0, - load_edge_cb: 0, arch_ext_need: 0, arch_head_need: 0, arch_head_hit: 0, @@ -855,8 +778,6 @@ pub(crate) fn sample( let thr = super::confirm::confirm_thr_stats::sample_and_reset(); let stamp_sub = rbitcoin_consensus::plan_stamp_sub_stats::sample_and_reset(); let ( - recon_ns, - wire_ns, connect_ns, script_ns, class_c_ns, @@ -865,13 +786,8 @@ pub(crate) fn sample( tip_ns, utxo_apply_ns, phase_blks, - resolve_ns, load_ns, - _unpin_ns, - cache_tip_ns, spend_ranged, - spend_idx, - spend_skip, structural_ns, structural_spent_ns, structural_create_h_ns, @@ -879,9 +795,6 @@ pub(crate) fn sample( ) = rbitcoin_consensus::confirm_phase_stats::sample_and_reset(); let (class_a_ns, ensure_ns) = rbitcoin_consensus::confirm_phase_stats::sample_class_a_ensure_and_reset(); - let recent_pub_ns = rbitcoin_consensus::confirm_phase_stats::sample_write_recent_and_reset(); - let (recent_idx_ns, recent_clone_ns) = - rbitcoin_consensus::confirm_phase_stats::sample_write_recent_parts_and_reset(); let (drain_join_ns, dequeue_ns) = rbitcoin_consensus::confirm_phase_stats::sample_write_residuals_and_reset(); let (pins_take_ns, pins_map_ns, head_sub_ns) = @@ -893,23 +806,15 @@ pub(crate) fn sample( rbitcoin_consensus::confirm_phase_stats::sample_spent_sub_and_reset(); let (script_jobs, script_skip) = rbitcoin_consensus::confirm_phase_stats::sample_script_mix_and_reset(); - let (ann_ns, ann_n, ann_pread_skip, ann_pread) = + let (ann_ns, ann_n, ann_pread_skip) = rbitcoin_consensus::confirm_phase_stats::sample_spend_ann_and_reset(); let (meta_ns, meta_n) = rbitcoin_consensus::confirm_phase_stats::sample_spend_meta_and_reset(); let (ensure_res_hit, ensure_cold_n) = rbitcoin_consensus::confirm_phase_stats::sample_ensure_mix_and_reset(); let (asm_prevout_ns, asm_sigop_ns, asm_final_ns, asm_job_ns) = rbitcoin_consensus::confirm_phase_stats::sample_assemble_and_reset(); - let ( - asm_in_n, - asm_prev_batch_ns, - asm_prev_batch_n, - asm_prev_same_ns, - asm_prev_same_n, - asm_prev_cold_ns, - asm_prev_cold_n, - asm_prev_fk_ns, - ) = rbitcoin_consensus::confirm_phase_stats::sample_assemble_prevout_detail_and_reset(); + let (asm_in_n, asm_prev_batch_n, asm_prev_same_n, asm_prev_cold_n) = + rbitcoin_consensus::confirm_phase_stats::sample_assemble_prevout_detail_and_reset(); let (asm_cold_null_fk_n, asm_cold_not_pin_n, asm_cold_txid_mismatch_n, asm_cold_vout_miss_n) = rbitcoin_consensus::confirm_phase_stats::sample_assemble_cold_why_and_reset(); let (prep_wire_arc_ns, prep_struct_ns, prep_header_ns, prep_prepare_ns, prep_filter_plan_ns) = @@ -948,8 +853,6 @@ pub(crate) fn sample( dominant: hot.dominant(), live: hot.confirm_live, phase_blks, - recon_ms: ns_ms(recon_ns), - wire_ms: ns_ms(wire_ns), connect_ms: ns_ms(connect_ns), script_ms: ns_ms(script_ns), write: WriteStageSample { @@ -967,10 +870,6 @@ pub(crate) fn sample( utxo_apply_ns, tweak_ms: ns_ms(tweak_ns), tweak_ns, - cache_tip_ms: ns_ms(cache_tip_ns), - cache_tip_ns, - recent_pub_ms: ns_ms(recent_pub_ns), - recent_pub_ns, pins_ms: ns_ms(pins_ns), pins_ns, head_sub_ms: ns_ms(head_sub_ns), @@ -984,8 +883,6 @@ pub(crate) fn sample( }, ensure_res_hit, ensure_cold_n, - recent_idx_ms: ns_ms(recent_idx_ns), - recent_clone_ms: ns_ms(recent_clone_ns), pins_take_ms: ns_ms(pins_take_ns), pins_map_ms: ns_ms(pins_map_ns), asm_prevout_ms: ns_ms(asm_prevout_ns), @@ -993,17 +890,13 @@ pub(crate) fn sample( asm_final_ms: ns_ms(asm_final_ns), asm_job_ms: ns_ms(asm_job_ns), asm_in_n, - asm_prev_batch_ms: ns_ms(asm_prev_batch_ns), asm_prev_batch_n, - asm_prev_same_ms: ns_ms(asm_prev_same_ns), asm_prev_same_n, - asm_prev_cold_ms: ns_ms(asm_prev_cold_ns), asm_prev_cold_n, asm_cold_null_fk_n, asm_cold_not_pin_n, asm_cold_txid_mismatch_n, asm_cold_vout_miss_n, - asm_prev_fk_ms: ns_ms(asm_prev_fk_ns), strong_ms: ns_ms(strong_ns), structural_spent_ms: ns_ms(structural_spent_ns), spent_abs_ms: ns_ms(spent_abs_ns), @@ -1013,23 +906,17 @@ pub(crate) fn sample( structural_create_h_ms: ns_ms(structural_create_h_ns), structural_bip68_ms: ns_ms(structural_bip68_ns), spend_ranged, - spend_idx, - spend_skip, ann_ms: ns_ms(ann_ns), ann_n, ann_pread_skip, - ann_pread, meta_ms: ns_ms(meta_ns), meta_n, - resolve_ms: ns_ms(resolve_ns), load_ms: ns_ms(load_ns), prep_wire_arc_ms: ns_ms(prep_wire_arc_ns), prep_struct_ms: ns_ms(prep_struct_ns), prep_header_ms: ns_ms(prep_header_ns), prep_prepare_ms: ns_ms(prep_prepare_ns), prep_filter_plan_ms: ns_ms(prep_filter_plan_ns), - recon_ns, - wire_ns, connect_ns, script_ns, strong_ns, @@ -1037,7 +924,6 @@ pub(crate) fn sample( structural_spent_ns, structural_create_h_ns, structural_bip68_ns, - resolve_ns, load_ns, sh_runs, wf_body_store, @@ -1052,30 +938,21 @@ pub(crate) fn sample( load_win_ms: ns_ms(pw.ns), load_blocks: pw.blocks, load_utxo_parents: pw.utxo_parents, - load_creates: pw.creates, load_parent_unique: pw.parent_unique, load_pin_cache_body: pw.pin_cache_body, load_pin_plan: pw.pin_plan, load_pin_new: pw.pin_new, load_pin_body_ms: ns_ms(pw.pin_body_ns), - load_pin_new_meta_ms: ns_ms(pw.pin_new_meta_ns), load_plan_pin_ms: ns_ms(pw.plan_pin_ns), - load_pin_adopt_ms: ns_ms(pw.pin_adopt_ns), load_pin_range_fill_ms: ns_ms(pw.pin_range_fill_ns), load_pin_recent_outs_ms: ns_ms(pw.pin_recent_outs_ns), load_pin_contract_ms: ns_ms(pw.pin_contract_ns), - load_pin_publish_ms: ns_ms(pw.pin_publish_ns), load_cold_io_ms: ns_ms(pw.cold_io_ns), load_cold_range_ms: ns_ms(pw.cold_range_ns), load_cold_range_n: pw.cold_range_n, load_cold_range_body_ms: ns_ms(pw.cold_range_body_ns), load_cold_range_decode_ms: ns_ms(pw.cold_range_decode_ns), - load_cold_idx_ms: ns_ms(pw.cold_idx_ns), - load_cold_idx_n: pw.cold_idx_n, - load_cold_decode_ms: ns_ms(pw.cold_decode_ns), load_body_tx_reads: pw.body_tx, - load_parent_tx_reads: pw.parent_tx, - load_missing_parents: pw.missing, load_ready_through, cache_bodies, cache_plans, @@ -1133,14 +1010,8 @@ pub(crate) fn sample( plan_already: dens.already, plan_cold: dens.cold, plan_same_batch: dens.unresolved, - load_hdr_ms: ns_ms(pw.header_ns), - load_decode_ms: ns_ms(pw.body_decode_ns), load_thin_ms: ns_ms(pw.thin_ns), load_parent_pin_ms: ns_ms(pw.parent_pin_ns), - load_cache_put_ms: ns_ms(pw.cache_put_ns), - load_edge_same: pw.edge_same_batch, - load_edge_fk: pw.edge_fk, - load_edge_cb: pw.edge_coinbase, arch_ext_need: arch_res.ext_need, arch_head_need: arch_res.head_need, arch_head_hit: arch_res.head_hit, @@ -1246,7 +1117,7 @@ fn plan_batch_ms(s: &IbdPerfSample) -> u64 { /// /// Class A + denserels ensure + structural + **Class C tables** (strong+tip) + /// **SH** (parallel with strong on tip; was previously folded into a join-wall -/// `class_c`) + spend annotate + SP tweaks + tip GC. +/// `class_c`) + spend annotate + SP tweaks. fn write_stage_ms(s: &IbdPerfSample) -> u64 { s.write.stage_ms() } @@ -1398,10 +1269,6 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { s.plan_cold_io_ms, )); } - append_nz(&mut out, "recon_ms", s.recon_ms); - append_nz(&mut out, "wire_ms", s.wire_ms); - append_nz(&mut out, "resolve_ms", s.resolve_ms); - // CACHE_BODY is adopt / plan / in-flight / same-batch only — this // window's cold range-fills increment PIN_NEW, not cache. let pin_hit_pct = { @@ -1418,16 +1285,10 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { } else { s.load_pin_body_ms }; - let cold_io_ms = if s.load_cold_io_ms > 0 { - s.load_cold_io_ms - } else { - s.load_pin_new_meta_ms - }; - let cold_dec_ms = s.load_cold_decode_ms; + let cold_io_ms = s.load_cold_io_ms; let cold_range_ms = s.load_cold_range_ms; - let cold_idx_ms = s.load_cold_idx_ms; - let cold_for_us = if cold_range_ms + cold_idx_ms > 0 { - cold_range_ms.saturating_add(cold_idx_ms) + let cold_for_us = if cold_range_ms > 0 { + cold_range_ms } else { cold_io_ms }; @@ -1455,12 +1316,12 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { out.push_str(&format!( " | load blks={} total={}ms pre_asm={}ms(wire_arc={}ms struct={}ms header={}ms prepare={}ms \ filter_plan={}ms plan_batch={}ms pin={}ms) \ - assemble={}ms(prevout={} us/in={} batch={}/n={} same={}/n={} cold={}/n={} \ - cold_why(null_fk={} not_pin={} mismatch={} vout_miss={}) fk={}ms \ + assemble={}ms(prevout={} us/in={} batch_n={} same_n={} cold_n={} \ + cold_why(null_fk={} not_pin={} mismatch={} vout_miss={}) \ sigop={} final={} job={}) \ - pin(thin={}ms plan={}ms/n={} cold_range={}ms(body={} dec={})/n={} cold_idx={}ms/n={} cold_io={}ms cold_dec={}ms us/new={} \ - adopt={}ms recent_outs={}ms range_fill={}ms contract={}ms publish={}ms) \ - pin_hit%={} pin_plan={} pin_new={} body_io={} parent_io={}", + pin(thin={}ms plan={}ms/n={} cold_range={}ms(body={} dec={})/n={} cold_io={}ms us/new={} \ + recent_outs={}ms range_fill={}ms contract={}ms) \ + pin_hit%={} pin_plan={} pin_new={} body_io={}", s.load_blocks, load_wall_ms, pre_assemble, @@ -1474,17 +1335,13 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { s.connect_ms, s.asm_prevout_ms, asm_prev_us_per_in, - s.asm_prev_batch_ms, s.asm_prev_batch_n, - s.asm_prev_same_ms, s.asm_prev_same_n, - s.asm_prev_cold_ms, s.asm_prev_cold_n, s.asm_cold_null_fk_n, s.asm_cold_not_pin_n, s.asm_cold_txid_mismatch_n, s.asm_cold_vout_miss_n, - s.asm_prev_fk_ms, s.asm_sigop_ms, s.asm_final_ms, s.asm_job_ms, @@ -1495,41 +1352,26 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { s.load_cold_range_body_ms, s.load_cold_range_decode_ms, s.load_cold_range_n, - cold_idx_ms, - s.load_cold_idx_n, cold_io_ms, - cold_dec_ms, pin_cold_us_per, - s.load_pin_adopt_ms, s.load_pin_recent_outs_ms, s.load_pin_range_fill_ms, s.load_pin_contract_ms, - s.load_pin_publish_ms, pin_hit_pct, s.load_pin_plan, s.load_pin_new, s.load_body_tx_reads, - s.load_parent_tx_reads, )); if s.load_win_ms > 0 { out.push_str(&format!(" pin_win={}ms", s.load_win_ms)); } - if s.load_edge_same > 0 || s.load_edge_fk > 0 || s.load_edge_cb > 0 { - out.push_str(&format!( - " edges same={} fk={} cb={}", - s.load_edge_same, s.load_edge_fk, s.load_edge_cb - )); - } - if s.load_missing_parents > 0 { - out.push_str(&format!(" miss_p={}", s.load_missing_parents)); - } out.push_str(&format!( " | write class_a={}ms ensure={}ms(pin={} cold={}) struct={}ms(spent={} create_h={} bip68={}) \ spent_sub(abs={} strong={} cold={} pending={}) \ - class_c={}ms class_c_join={}ms sh={}ms spend={}ms tweaks={}ms tip_gc={}ms recent_pub={}ms(idx={} clone={}) \ + class_c={}ms class_c_join={}ms sh={}ms spend={}ms tweaks={}ms \ pins={}ms(take={} map={}) head_sub={}ms drain_join={}ms dequeue={}ms other={}ms \ - ann={}ms/n={} pread_skip={} pread={} \ + ann={}ms/n={} pread_skip={} \ meta={}ms/n={}", s.write.class_a_ms, s.write.ensure_ms, @@ -1548,10 +1390,6 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { s.write.sh_ms, s.write.utxo_ms, s.write.tweak_ms, - s.write.cache_tip_ms, - s.write.recent_pub_ms, - s.recent_idx_ms, - s.recent_clone_ms, s.write.pins_ms, s.pins_take_ms, s.pins_map_ms, @@ -1562,7 +1400,6 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { s.ann_ms, s.ann_n, s.ann_pread_skip, - s.ann_pread, s.meta_ms, s.meta_n, )); @@ -1576,12 +1413,6 @@ pub(crate) fn format_info(s: &IbdPerfSample) -> String { )); } append_nz(&mut out, "strong_ms", s.strong_ms); - if s.spend_idx > 0 || s.spend_skip > 0 { - out.push_str(&format!( - " spend_mix(r={} i={} skip={})", - s.spend_ranged, s.spend_idx, s.spend_skip - )); - } let conf_q = super::confirm::format_conf_q( s.conf_pipe.load_batches, @@ -1627,7 +1458,7 @@ pub(crate) fn format_debug(s: &IbdPerfSample) -> String { let mut out = format!( "ibd: perf_dbg us/blk load={} (pre_asm={} assemble={}) script={} write={} \ class_a={} ensure={} struct={} spent={} create_h={} bip68={} class_c={} sh={} \ - spend={}(r={} i={} skip={}) tweaks={} tip_gc={} recent_pub={} pins={} head_sub={} drain_join={} dequeue={}", + spend={}(r={}) tweaks={} pins={} head_sub={} drain_join={} dequeue={}", us(prep_ns), us(s.load_ns), us(s.connect_ns), @@ -1643,19 +1474,12 @@ pub(crate) fn format_debug(s: &IbdPerfSample) -> String { us(s.write.sh_ns), us(s.write.utxo_apply_ns), s.spend_ranged, - s.spend_idx, - s.spend_skip, us(s.write.tweak_ns), - us(s.write.cache_tip_ns), - us(s.write.recent_pub_ns), us(s.write.pins_ns), us(s.write.head_sub_ns), us(s.write.drain_join_ns), us(s.write.dequeue_ns), ); - append_nz(&mut out, "recon_us", us(s.recon_ns)); - append_nz(&mut out, "wire_us", us(s.wire_ns)); - append_nz(&mut out, "resolve_us", us(s.resolve_ns)); append_nz(&mut out, "strong_us", us(s.strong_ns)); append_nz(&mut out, "tip_us", us(s.tip_ns)); if s.wf_body_store > 0 || s.wf_store_body_ms > 0 { @@ -1686,7 +1510,7 @@ pub(crate) fn format_debug(s: &IbdPerfSample) -> String { ); let bq_mib = s.bq_bytes / (1024 * 1024); out.push_str(&format!( - " | bq soft={}/{} RAM={}MiB | {conf_q} | load thru={} bodies={} plans={} win_ms={} blks={} utxo_p={} creates={} uniq_p={} pin_cache={} pin_new={} body_io={} parent_io={}", + " | bq soft={}/{} RAM={}MiB | {conf_q} | load thru={} bodies={} plans={} win_ms={} blks={} utxo_p={} uniq_p={} pin_cache={} pin_new={} body_io={}", s.bq_count, s.bq_soft_stop, bq_mib, @@ -1696,27 +1520,14 @@ pub(crate) fn format_debug(s: &IbdPerfSample) -> String { s.load_win_ms, s.load_blocks, s.load_utxo_parents, - s.load_creates, s.load_parent_unique, s.load_pin_cache_body, s.load_pin_new, s.load_body_tx_reads, - s.load_parent_tx_reads, - )); - append_nz(&mut out, "miss_p", s.load_missing_parents); - out.push_str(&format!( - " phases hdr={} dec={} thin={} pin={} put={} pin_sub body={} new={}", - s.load_hdr_ms, - s.load_decode_ms, - s.load_thin_ms, - s.load_parent_pin_ms, - s.load_cache_put_ms, - s.load_pin_body_ms, - s.load_pin_new_meta_ms, )); out.push_str(&format!( - " edges same={} fk={} cb={}", - s.load_edge_same, s.load_edge_fk, s.load_edge_cb, + " phases thin={} pin={} pin_sub body={}", + s.load_thin_ms, s.load_parent_pin_ms, s.load_pin_body_ms, )); out.push_str(&format!(" sh_runs={}", s.sh_runs)); @@ -1875,10 +1686,6 @@ pub(crate) fn format_sizes(s: &IbdPerfSample) -> String { }; let bq_mib = s.bq_bytes / (1024 * 1024); let if_mib = o.inflight_bytes / (1024 * 1024); - let ps_mib = o.pstore_bytes / (1024 * 1024); - // CreatePin payload bytes (Arc-shared with in-flight while overlapping). - let recent_bytes = o.recent_pin_bytes; - let recent_mib = recent_bytes / (1024 * 1024); let h2h_mib = (o.h2h_keys as u64).saturating_mul(48) / (1024 * 1024); let fence_mib = (o.fence_runs as u64).saturating_mul(16) / (1024 * 1024); let conf_wire_mib = (load_wire_mib @@ -1890,8 +1697,6 @@ pub(crate) fn format_sizes(s: &IbdPerfSample) -> String { let class_c_l2_mib = h.class_c_l2_bytes / (1024 * 1024); let accounted_mib = bq_mib .saturating_add(if_mib) - .saturating_add(ps_mib) - .saturating_add(recent_mib) .saturating_add(h2h_mib) .saturating_add(fence_mib) .saturating_add(conf_wire_mib) @@ -1909,9 +1714,8 @@ pub(crate) fn format_sizes(s: &IbdPerfSample) -> String { | conf_plans={} \ | conf loadq={}/{} blks={} wire={}MiB scriptq={}/{} blks={} wire={}MiB writeq={}/{} blks={} wire={}MiB parents={} \ feed ready={} inflight={} \ - | heap bq={}MiB iflight={}L/{}pin≈{}MiB recent={}h live={}k/pub={}k/ov={} fifo={}k≈{}MiB \ + | heap bq={}MiB iflight={}L/{}pin≈{}MiB \ h2h={}k≈{}MiB fence={}≈{}MiB \ - pstore weak={}/live={}≈{}MiB \ wire={}MiB fuse8={}MiB mphf_g={}MiB open_keys={}MiB class_c_l2={}MiB \ accounted≈{}MiB residual≈{}MiB \ | txhead bits={} entry={}B slots={} occ={} body={}MiB segs={} sealed={} class_a={} \ @@ -1958,19 +1762,10 @@ pub(crate) fn format_sizes(s: &IbdPerfSample) -> String { o.inflight_layers, o.inflight_pins, if_mib, - o.recent_heights, - o.recent_keys, - o.recent_pub_keys, - o.recent_overlay_keys, - o.recent_fifo_keys, - recent_mib, o.h2h_keys, h2h_mib, o.fence_runs, fence_mib, - o.pstore_weak, - o.pstore_live, - ps_mib, conf_wire_mib, fuse8_mib, mphf_g_mib, @@ -2036,23 +1831,22 @@ mod tests { write.sh_ms = 16; write.utxo_ms = 32; write.tweak_ms = 64; - write.cache_tip_ms = 128; write.drain_join_ms = 0; write.dequeue_ms = 0; assert_eq!( write.stage_ms(), - 255, - "inventory: class_a+ensure+struct+class_c+sh+spend+tweaks+tip_gc+recent_pub+pins+head_sub+drain_join+dequeue" + 127, + "inventory: class_a+ensure+struct+class_c+sh+spend+tweaks+pins+head_sub+drain_join+dequeue" ); let mut s = IbdPerfSample::default(); s.write = write; - assert_eq!(write_stage_ms(&s), 255); + assert_eq!(write_stage_ms(&s), 127); let line = format_info(&s); - assert!(line.contains("write=255ms"), "{line}"); + assert!(line.contains("write=127ms"), "{line}"); assert!(line.contains("tweaks=64ms"), "{line}"); - assert!(line.contains("tip_gc=128ms"), "{line}"); + assert!(!line.contains("tip_gc="), "{line}"); assert!(line.contains("spend=32ms"), "{line}"); - assert!(line.contains("recent_pub=0ms(idx=0 clone=0)"), "{line}"); + assert!(!line.contains("recent_pub="), "{line}"); assert!(line.contains("class_c_join=0ms"), "{line}"); assert!(line.contains("drain_join=0ms"), "{line}"); assert!(line.contains("dequeue=0ms"), "{line}"); @@ -2095,9 +1889,8 @@ mod tests { s.write.sh_ms = 100; // SH exclusive (parallel with strong; counted separately) s.write.utxo_ms = 25; s.write.tweak_ms = 80; - s.write.cache_tip_ms = 5; - // 15+2+50+40+100+25+80+5 = 317 - assert_eq!(write_stage_ms(&s), 317); + // 15+2+50+40+100+25+80 = 312 + assert_eq!(write_stage_ms(&s), 312); } #[test] @@ -2126,41 +1919,12 @@ mod tests { s.write.class_a_ms = 12; s.write.ensure_ms = 3; s.write.class_c_ms = 4; - s.recon_ms = 99; - s.wire_ms = 88; - s.resolve_ms = 77; - s.recon_ns = 10_000_000; - s.wire_ns = 9_000_000; - s.resolve_ns = 8_000_000; - s.load_parent_tx_reads = 12; - s.load_creates = 50; - s.load_missing_parents = 3; - s.load_cache_put_ms = 2; - s.load_hdr_ms = 5; - s.load_decode_ms = 6; - s.load_edge_same = 10; - s.load_edge_fk = 5; - s.load_edge_cb = 1; - s.load_cold_idx_ms = 400; - s.load_cold_idx_n = 2; - s.load_cold_decode_ms = 10; - s.load_pin_new_meta_ms = 14; - s.write.recent_pub_ms = 6; - s.write.recent_pub_ns = 6_000_000; - s.write.cache_tip_ms = 5; - s.write.cache_tip_ns = 5_000_000; - s.spend_idx = 2; - s.spend_skip = 1; - s.ann_pread = 4; - s.asm_prev_batch_ms = 2000; - s.asm_prev_same_ms = 50; - s.asm_prev_cold_ms = 250; - s.asm_prev_fk_ms = 10; - s.owned.pstore_weak = 20_000; - s.owned.pstore_live = 8_000; - s.owned.pstore_bytes = 16 * 1024 * 1024; - s.owned.recent_heights = 12; - s.owned.recent_keys = 400; + s.load_body_tx_reads = 12; + s.load_pin_new = 6; + s.ann_pread_skip = 4; + s.asm_prev_batch_n = 2000; + s.asm_prev_same_n = 50; + s.asm_prev_cold_n = 250; let info = format_info(&s); let dbg = format_debug(&s); let sizes = format_sizes(&s); @@ -2210,7 +1974,6 @@ mod tests { s.hole = 0; s.peers = 16; s.phase_blks = 32; - s.recon_ms = 100; s.script_ms = 20; s.load_ms = 30; s.connect_ms = 8; @@ -2219,7 +1982,6 @@ mod tests { s.write.class_c_ms = 40; s.write.utxo_ms = 25; s.write.tweak_ms = 7; - s.write.cache_tip_ms = 5; s.dominant = "confirm"; s.live = Some((100, 32, 8000, 1500)); s.confirm_reject_stops = 2; @@ -2280,15 +2042,15 @@ mod tests { !line.contains("connect="), "assemble is inside load, not a peer stage: {line}" ); - // write = class_a(12)+ensure(3)+class_c(40)+sh(0)+spend(25)+tweaks(7)+tip_gc(5) = 92 - assert!(line.contains("write=92ms"), "{line}"); + // write = class_a(12)+ensure(3)+class_c(40)+sh(0)+spend(25)+tweaks(7) = 87 + assert!(line.contains("write=87ms"), "{line}"); assert!(line.contains("class_a=12ms"), "{line}"); assert!(line.contains("ensure=3ms"), "{line}"); assert!(line.contains("class_c=40ms"), "{line}"); assert!(line.contains("spend=25ms"), "{line}"); assert!(line.contains("tweaks=7ms"), "{line}"); assert!(line.contains("struct=0ms"), "{line}"); - assert!(line.contains("recon_ms=100"), "{line}"); // non-zero only + assert!(!line.contains("recon_ms="), "{line}"); assert!(!line.contains("prefetch"), "{line}"); assert!(!line.contains("unpin"), "{line}"); assert!(line.contains("loop confirm"), "{line}"); @@ -2304,14 +2066,11 @@ mod tests { s.load_pin_cache_body = 8; s.load_pin_new = 12; s.load_body_tx_reads = 400; - s.load_parent_tx_reads = 12; s.load_win_ms = 40; s.load_thin_ms = 5; - s.load_decode_ms = 15; - s.load_cache_put_ms = 2; s.load_parent_pin_ms = 18; s.load_pin_body_ms = 4; - s.load_pin_new_meta_ms = 14; + s.load_cold_io_ms = 14; s.sh_runs = 3; s.write.structural_ms = 50; s.structural_spent_ms = 30; @@ -2325,7 +2084,8 @@ mod tests { // pin_residency slot always 0 (process pin FIFO removed); pin_plan_cache label retired. assert!(!line.contains("pin_res="), "{line}"); assert!(line.contains("pin_new=12"), "{line}"); - assert!(line.contains("body_io=400 parent_io=12"), "{line}"); + assert!(line.contains("body_io=400"), "{line}"); + assert!(!line.contains("parent_io="), "{line}"); s.spent_abs_ms = 20; s.spent_strong_ms = 5; s.spent_cold_ms = 3; @@ -2339,8 +2099,8 @@ mod tests { line.contains("spent_sub(abs=20 strong=5 cold=3 pending=2)"), "{line}" ); - // write = 12+3+50+40+25+7+5 = 142 - assert!(line.contains("write=142ms"), "{line}"); + // write = 12+3+50+40+25+7 = 137 + assert!(line.contains("write=137ms"), "{line}"); assert!(line.contains("class_a_sub(body=7 head=2"), "{line}"); assert!(line.contains("pre_asm=30ms"), "{line}"); assert!(line.contains("assemble=8ms"), "{line}"); @@ -2363,8 +2123,8 @@ mod tests { assert!(line.contains("us/in="), "{line}"); assert!(line.contains("us/new="), "{line}"); assert!(line.contains("cold_range="), "{line}"); - assert!(line.contains("cold_idx="), "{line}"); - assert!(line.contains("batch="), "{line}"); + assert!(!line.contains("cold_idx="), "{line}"); + assert!(line.contains("batch_n="), "{line}"); assert!(!line.contains("thin[col="), "{line}"); assert!(!line.contains("by_fk="), "{line}"); assert!(!line.contains("pin_cached="), "{line}"); @@ -2382,40 +2142,31 @@ mod tests { s.load_blocks = 10; s.asm_prevout_ms = 2500; s.asm_in_n = 50_000; - s.asm_prev_batch_ms = 2000; s.asm_prev_batch_n = 40_000; - s.asm_prev_same_ms = 50; s.asm_prev_same_n = 2_000; - s.asm_prev_cold_ms = 250; s.asm_prev_cold_n = 3_000; - s.asm_prev_fk_ms = 10; s.asm_sigop_ms = 2; s.asm_final_ms = 0; s.asm_job_ms = 40; s.load_thin_ms = 7; s.load_plan_pin_ms = 100; s.load_pin_plan = 20_000; - s.load_pin_adopt_ms = 15; s.load_pin_recent_outs_ms = 8; s.load_pin_range_fill_ms = 40; s.load_pin_contract_ms = 25; - s.load_pin_publish_ms = 12; s.load_cold_range_ms = 1200; s.load_cold_range_n = 4_000; - s.load_cold_idx_ms = 400; - s.load_cold_idx_n = 2_000; s.load_cold_io_ms = 1600; - s.load_cold_decode_ms = 10; s.load_pin_new = 6_000; s.load_pin_cache_body = 30_000; let line = format_info(&s); // Residual pin sub-timers named in pin(...) block. assert!(line.contains("thin=7ms"), "{line}"); - assert!(line.contains("adopt=15ms"), "{line}"); + assert!(!line.contains("adopt="), "{line}"); assert!(line.contains("recent_outs=8ms"), "{line}"); assert!(line.contains("range_fill=40ms"), "{line}"); assert!(line.contains("contract=25ms"), "{line}"); - assert!(line.contains("publish=12ms"), "{line}"); + assert!(!line.contains("publish="), "{line}"); // I1: total = load+connect = 5000; pin=1800; asm=3000; other=200 assert!( line.contains("load_budget total=5000ms pin=1800ms asm=3000ms other=200ms"), @@ -2423,13 +2174,13 @@ mod tests { ); // I3: us/in = 2500*1000/50000 = 50 assert!(line.contains("us/in=50"), "{line}"); - assert!(line.contains("batch=2000/n=40000"), "{line}"); + assert!(line.contains("batch_n=40000"), "{line}"); assert!(!line.contains("res=/n="), "{line}"); assert!(!line.contains("res_lk"), "{line}"); - assert!(line.contains("same=50/n=2000"), "{line}"); - assert!(line.contains("cold=250/n=3000"), "{line}"); + assert!(line.contains("same_n=2000"), "{line}"); + assert!(line.contains("cold_n=3000"), "{line}"); assert!(line.contains("cold_why(null_fk="), "{line}"); - assert!(line.contains("fk=10ms"), "{line}"); + assert!(!line.contains(" fk="), "{line}"); // N1 reason breakdown when set. s.asm_cold_null_fk_n = 10; s.asm_cold_not_pin_n = 2900; @@ -2440,7 +2191,7 @@ mod tests { line.contains("cold_why(null_fk=10 not_pin=2900 mismatch=50 vout_miss=40)"), "{line}" ); - // I2: us/new = (1200+400)*1000/6000 = 266 + // I2: us/new = 1200*1000/6000 = 200 assert!(line.contains("cold_range=1200ms(body="), "{line}"); s.load_cold_range_body_ms = 800; s.load_cold_range_decode_ms = 400; @@ -2449,8 +2200,8 @@ mod tests { line.contains("cold_range=1200ms(body=800 dec=400)/n=4000"), "{line}" ); - assert!(line.contains("cold_idx=400ms/n=2000"), "{line}"); - assert!(line.contains("us/new=266"), "{line}"); + assert!(!line.contains("cold_idx="), "{line}"); + assert!(line.contains("us/new=200"), "{line}"); assert!(!line.contains("res_lk"), "{line}"); assert!(!line.contains("pin_res="), "{line}"); } @@ -2526,7 +2277,6 @@ mod tests { s.sh_head_ms = 4; s.wf_body_store = 1; s.wf_store_body_ms = 2; - s.load_missing_parents = 3; s.thr_lookup_stamp_ms = 1; s.stamp_struct_ms = 8; s.stamp_struct_txid_ms = 6; @@ -2604,12 +2354,9 @@ mod tests { fn format_debug_has_detail_tokens() { let mut s = IbdPerfSample::default(); s.phase_blks = 10; - s.recon_ns = 10_000_000; // 1ms/blk → 1000 us/blk s.write.utxo_apply_ns = 5_000_000; // 500 us/blk s.write.tweak_ns = 3_000_000; // 300 us/blk s.spend_ranged = 10; - s.spend_idx = 2; - s.spend_skip = 0; s.wf_body_store = 3; s.wf_store_body_ms = 50; // (no cache/lock fields — pruned) @@ -2621,14 +2368,9 @@ mod tests { s.load_ready_through = 200; s.load_blocks = 16; s.load_utxo_parents = 100; - s.load_creates = 50; s.load_body_tx_reads = 200; - s.load_parent_tx_reads = 50; s.load_pin_cache_body = 0; s.load_pin_new = 38; - s.load_edge_same = 10; - s.load_edge_fk = 5; - s.load_edge_cb = 1; s.sh_collect_ms = 12; s.sh_runs = 2; s.arch_ext_need = 100; @@ -2643,7 +2385,7 @@ mod tests { assert!(line.contains("class_a="), "{line}"); assert!(line.contains("ensure="), "{line}"); assert!(line.contains("write="), "{line}"); - assert!(line.contains("spend=500(r=10 i=2 skip=0)"), "{line}"); + assert!(line.contains("spend=500(r=10)"), "{line}"); assert!(line.contains("tweaks=300"), "{line}"); assert!(!line.contains("prefetch="), "{line}"); assert!(!line.contains("wave body="), "{line}"); @@ -2663,13 +2405,14 @@ mod tests { ); assert!(line.contains("thru=200"), "{line}"); assert!(line.contains("utxo_p=100"), "{line}"); - assert!(line.contains("creates=50"), "{line}"); - assert!(line.contains("body_io=200 parent_io=50"), "{line}"); + assert!(!line.contains("creates="), "{line}"); + assert!(line.contains("body_io=200"), "{line}"); + assert!(!line.contains("parent_io="), "{line}"); assert!(line.contains("pin_cache=0"), "{line}"); assert!(!line.contains("pin_res="), "{line}"); assert!(line.contains("pin_new=38"), "{line}"); assert!(!line.contains("pin_cached="), "{line}"); - assert!(line.contains("edges same=10 fk=5 cb=1"), "{line}"); + assert!(!line.contains("edges same="), "{line}"); assert!(line.contains("sh_runs=2"), "{line}"); assert!(line.contains("plan_batch "), "{line}"); assert!(!line.contains("res_txid"), "{line}"); @@ -2721,16 +2464,8 @@ mod tests { s.owned.inflight_layers = 3; s.owned.inflight_pins = 12_000; s.owned.inflight_bytes = 48 * 1024 * 1024; - s.owned.recent_heights = 12; - s.owned.recent_keys = 400; - s.owned.recent_pub_keys = 400; - s.owned.recent_overlay_keys = 0; - s.owned.recent_fifo_keys = 400; s.owned.h2h_keys = 50; s.owned.fence_runs = 10; - s.owned.pstore_weak = 20_000; - s.owned.pstore_live = 8_000; - s.owned.pstore_bytes = 16 * 1024 * 1024; s.bq_count = 4; s.bq_bytes = 32 * 1024 * 1024; s.bq_soft_stop = 256; @@ -2788,13 +2523,14 @@ mod tests { assert!(line.contains("segs=3 sealed=2"), "{line}"); assert!(line.contains("class_a=2000000"), "{line}"); assert!( - line.contains("heap bq=32MiB iflight=3L/12000pin≈48MiB recent=12h live=400k/pub=400k/ov=0 fifo=400k≈0MiB"), + line.contains("heap bq=32MiB iflight=3L/12000pin≈48MiB"), "{line}" ); assert!(!line.contains("union="), "{line}"); + assert!(!line.contains("recent="), "{line}"); assert!(line.contains("h2h=50k≈0MiB"), "{line}"); assert!(line.contains("fence=10≈0MiB"), "{line}"); - assert!(line.contains("pstore weak=20000/live=8000≈16MiB"), "{line}"); + assert!(!line.contains("pstore"), "{line}"); assert!(line.contains("accounted≈"), "{line}"); assert!(line.contains("residual≈"), "{line}"); assert!(line.contains("fuse8="), "{line}"); @@ -2889,24 +2625,19 @@ mod tests { assert!(line.contains("lookup_thr busy="), "{line}"); assert!(line.contains("ready=0"), "{line}"); - // Edge format arms: spend_mix, miss_p, headers_done, zero pin_hit. + // Edge format arms: headers_done, zero pin_hit. let mut edge = s.clone(); - edge.spend_idx = 2; - edge.spend_skip = 1; edge.spend_ranged = 3; - edge.load_missing_parents = 4; edge.load_pin_cache_body = 0; edge.load_pin_new = 0; edge.headers_done = true; - edge.wire_ms = 9; edge.strong_ms = 1; - edge.resolve_ms = 2; edge.drain_ms = 3; let info = format_info(&edge); - assert!(info.contains("spend_mix"), "{info}"); - assert!(info.contains("miss_p=4"), "{info}"); + assert!(!info.contains("spend_mix"), "{info}"); + assert!(!info.contains("miss_p="), "{info}"); assert!(info.contains("headers_done"), "{info}"); - assert!(info.contains("wire_ms=9"), "{info}"); + assert!(!info.contains("wire_ms="), "{info}"); assert!(info.contains("getdata=7"), "{info}"); assert!(info.contains("pin_hit%=0"), "{info}"); diff --git a/crates/rbitcoin-query/src/confirm_load.rs b/crates/rbitcoin-query/src/confirm_load.rs index 92ae1f195..626345938 100644 --- a/crates/rbitcoin-query/src/confirm_load.rs +++ b/crates/rbitcoin-query/src/confirm_load.rs @@ -14,7 +14,6 @@ pub type SpendEdges = U64Map>; pub struct ConfirmLoadStats { pub blocks: u32, pub utxo_parents: u32, - pub creates_registered: u32, /// Unique parent create fks pinned this call (after dedup). pub parent_unique: u32, /// Of `parent_unique`: filled without store denserels IO (same-batch / in-flight / adopt). @@ -23,26 +22,10 @@ pub struct ConfirmLoadStats { pub pin_new: u32, /// FIFO hit path resolve. pub pin_body_ns: u64, - /// pin_new meta/outs resolve (excludes spent timer). - pub pin_new_meta_ns: u64, - /// Same-batch create edges (identity known in-batch). - pub parent_cache_hits: u32, - /// Stamped create_fk on input, parent **not** in this batch (external fk). - pub edge_fk: u32, /// Body txs full-decoded (phase 1). pub body_tx_reads: u32, - /// Parent outs loaded from store (sparse pin). - pub full_tx_reads: u32, - /// Unstamped non-coinbase edges (should not occur on healthy v10 Class A). - pub missing_parents: u32, - /// Phase wall times (ns). - pub header_ns: u64, - pub body_decode_ns: u64, pub thin_ns: u64, pub parent_pin_ns: u64, - pub cache_put_ns: u64, - pub edge_same_batch: u32, - pub edge_coinbase: u32, } impl Query { diff --git a/crates/rbitcoin-query/src/in_flight.rs b/crates/rbitcoin-query/src/in_flight.rs index 3b142354f..b1916f9aa 100644 --- a/crates/rbitcoin-query/src/in_flight.rs +++ b/crates/rbitcoin-query/src/in_flight.rs @@ -264,12 +264,10 @@ mod tests { assert_eq!(entries, 2); assert!(bytes > 0, "expected non-zero approx bytes"); assert!(bytes < 4096, "bytes={bytes}"); - crate::process_mem_stats::note(packs, entries, bytes, 10, 2, 100); + crate::process_mem_stats::note(packs, entries, bytes); let s = crate::process_mem_stats::load(); assert_eq!(s.inflight_layers, 2); assert_eq!(s.inflight_pins, 2); - assert_eq!(s.pstore_weak, 10); - assert_eq!(s.pstore_live, 2); let again = m.size_snapshot(); assert_eq!( (packs, entries, bytes), diff --git a/crates/rbitcoin-query/src/lib.rs b/crates/rbitcoin-query/src/lib.rs index f81904437..a045c407f 100644 --- a/crates/rbitcoin-query/src/lib.rs +++ b/crates/rbitcoin-query/src/lib.rs @@ -69,20 +69,6 @@ pub struct ProcessOwnedSizes { pub inflight_layers: usize, pub inflight_pins: usize, pub inflight_bytes: u64, - /// Unused process pstore meters (always 0; BatchParents is batch-local). - pub pstore_weak: usize, - pub pstore_live: usize, - pub pstore_bytes: u64, - /// Write-published recent-create layer chain (layers / live keys). - pub recent_heights: usize, - pub recent_keys: usize, - /// Published layer keys (pending not included). - pub recent_pub_keys: usize, - pub recent_overlay_keys: usize, - /// Same as live keys (pending + published). - pub recent_fifo_keys: usize, - /// Live CreatePin payload bytes (not 96 B/key). - pub recent_pin_bytes: u64, /// Confirmed hash→height map entries. pub h2h_keys: usize, /// Height-fence run count (no Vec clone). @@ -93,33 +79,19 @@ pub struct ProcessOwnedSizes { /// Plan-thread published heap meters for structures not owned by [`Query`]. /// -/// Updated after each load note/prune ([`InFlight`]). IBD pstore counts stay 0. -/// Sampled by the ~5s IBD sizes line. +/// Updated after each load note/prune ([`InFlight`]). Sampled by the ~5s IBD sizes line. pub mod process_mem_stats { use std::sync::atomic::{AtomicU64, Ordering}; static INFLIGHT_LAYERS: AtomicU64 = AtomicU64::new(0); static INFLIGHT_PINS: AtomicU64 = AtomicU64::new(0); static INFLIGHT_BYTES: AtomicU64 = AtomicU64::new(0); - static PSTORE_WEAK: AtomicU64 = AtomicU64::new(0); - static PSTORE_LIVE: AtomicU64 = AtomicU64::new(0); - static PSTORE_BYTES: AtomicU64 = AtomicU64::new(0); - - /// Publish latest prep-ahead / parent-store occupancy (overwrite). - pub fn note( - inflight_layers: usize, - inflight_pins: usize, - inflight_bytes: u64, - pstore_weak: usize, - pstore_live: usize, - pstore_bytes: u64, - ) { + + /// Publish latest prep-ahead occupancy (overwrite). + pub fn note(inflight_layers: usize, inflight_pins: usize, inflight_bytes: u64) { INFLIGHT_LAYERS.store(inflight_layers as u64, Ordering::Relaxed); INFLIGHT_PINS.store(inflight_pins as u64, Ordering::Relaxed); INFLIGHT_BYTES.store(inflight_bytes, Ordering::Relaxed); - PSTORE_WEAK.store(pstore_weak as u64, Ordering::Relaxed); - PSTORE_LIVE.store(pstore_live as u64, Ordering::Relaxed); - PSTORE_BYTES.store(pstore_bytes, Ordering::Relaxed); } #[derive(Clone, Copy, Debug, Default)] @@ -127,9 +99,6 @@ pub mod process_mem_stats { pub inflight_layers: usize, pub inflight_pins: usize, pub inflight_bytes: u64, - pub pstore_weak: usize, - pub pstore_live: usize, - pub pstore_bytes: u64, } pub fn load() -> Snap { @@ -137,9 +106,6 @@ pub mod process_mem_stats { inflight_layers: INFLIGHT_LAYERS.load(Ordering::Relaxed) as usize, inflight_pins: INFLIGHT_PINS.load(Ordering::Relaxed) as usize, inflight_bytes: INFLIGHT_BYTES.load(Ordering::Relaxed), - pstore_weak: PSTORE_WEAK.load(Ordering::Relaxed) as usize, - pstore_live: PSTORE_LIVE.load(Ordering::Relaxed) as usize, - pstore_bytes: PSTORE_BYTES.load(Ordering::Relaxed), } } } @@ -177,7 +143,6 @@ pub mod confirm_load_stats { pub static NS: AtomicU64 = AtomicU64::new(0); pub static BLOCKS: AtomicU64 = AtomicU64::new(0); pub static UTXO_PARENTS: AtomicU64 = AtomicU64::new(0); - pub static CREATES: AtomicU64 = AtomicU64::new(0); pub static PARENT_UNIQUE: AtomicU64 = AtomicU64::new(0); /// Pin filled from same-batch / in-flight / pstore adopt (no Class A re-decode). pub static PIN_CACHE_BODY: AtomicU64 = AtomicU64::new(0); @@ -186,19 +151,14 @@ pub mod confirm_load_stats { /// Pin candidates that missed same-batch / in-flight / adopt (cold denserels). pub static PIN_NEW: AtomicU64 = AtomicU64::new(0); pub static PIN_BODY_NS: AtomicU64 = AtomicU64::new(0); - pub static PIN_NEW_META_NS: AtomicU64 = AtomicU64::new(0); /// Wire pin sub-walls (ns). pub static PLAN_PIN_NS: AtomicU64 = AtomicU64::new(0); - /// Pipeline store adopt (bulk Weak upgrade) wall. - pub static PIN_ADOPT_NS: AtomicU64 = AtomicU64::new(0); /// Post cold-range denserels: insert_owned into BatchParents (not IO). pub static PIN_RANGE_FILL_NS: AtomicU64 = AtomicU64::new(0); /// Stamp-carried CreatePin probe (after in-flight / same-batch, before range fill). pub static PIN_RECENT_OUTS_NS: AtomicU64 = AtomicU64::new(0); /// Final pin contract (contains + pin_covered) wall. pub static PIN_CONTRACT_NS: AtomicU64 = AtomicU64::new(0); - /// Pipeline store publish (bulk Weak insert + conflict merge) wall. - pub static PIN_PUBLISH_NS: AtomicU64 = AtomicU64::new(0); /// Cold denserels wall (range + idx). Prefer split fields when diagnosing. pub static COLD_IO_NS: AtomicU64 = AtomicU64::new(0); /// Cold denserels via plan stamp body range (`get_outs_by_range_batch`). @@ -208,24 +168,9 @@ pub mod confirm_load_stats { pub static COLD_RANGE_BODY_NS: AtomicU64 = AtomicU64::new(0); /// Sub-wall of cold range: sparse denserels decode (N2.0). pub static COLD_RANGE_DECODE_NS: AtomicU64 = AtomicU64::new(0); - /// Cold denserels via idx→body (`load_creates_once`). - pub static COLD_IDX_NS: AtomicU64 = AtomicU64::new(0); - pub static COLD_IDX_N: AtomicU64 = AtomicU64::new(0); - pub static COLD_DECODE_NS: AtomicU64 = AtomicU64::new(0); - pub static PARENT_CACHE_HITS: AtomicU64 = AtomicU64::new(0); - pub static FULL_TX_READS: AtomicU64 = AtomicU64::new(0); pub static BODY_TX_READS: AtomicU64 = AtomicU64::new(0); - pub static MISSING_PARENTS: AtomicU64 = AtomicU64::new(0); - /// Phase nanoseconds (sum over calls this window). - pub static HEADER_NS: AtomicU64 = AtomicU64::new(0); - pub static BODY_DECODE_NS: AtomicU64 = AtomicU64::new(0); pub static THIN_NS: AtomicU64 = AtomicU64::new(0); pub static PARENT_PIN_NS: AtomicU64 = AtomicU64::new(0); - pub static CACHE_PUT_NS: AtomicU64 = AtomicU64::new(0); - /// Thin edges: same-batch / stamped-fk / coinbase. - pub static EDGE_SAME_BATCH: AtomicU64 = AtomicU64::new(0); - pub static EDGE_FK: AtomicU64 = AtomicU64::new(0); - pub static EDGE_COINBASE: AtomicU64 = AtomicU64::new(0); /// One sampler snapshot (all counters reset). #[derive(Debug, Default, Clone, Copy)] @@ -233,39 +178,23 @@ pub mod confirm_load_stats { pub ns: u64, pub blocks: u64, pub utxo_parents: u64, - pub creates: u64, pub parent_unique: u64, pub pin_cache_body: u64, pub pin_plan: u64, pub pin_new: u64, pub pin_body_ns: u64, - pub pin_new_meta_ns: u64, pub plan_pin_ns: u64, - pub pin_adopt_ns: u64, pub pin_range_fill_ns: u64, pub pin_recent_outs_ns: u64, pub pin_contract_ns: u64, - pub pin_publish_ns: u64, pub cold_io_ns: u64, pub cold_range_ns: u64, pub cold_range_n: u64, pub cold_range_body_ns: u64, pub cold_range_decode_ns: u64, - pub cold_idx_ns: u64, - pub cold_idx_n: u64, - pub cold_decode_ns: u64, - pub cache_hits: u64, pub body_tx: u64, - pub parent_tx: u64, - pub missing: u64, - pub header_ns: u64, - pub body_decode_ns: u64, pub thin_ns: u64, pub parent_pin_ns: u64, - pub cache_put_ns: u64, - pub edge_same_batch: u64, - pub edge_fk: u64, - pub edge_coinbase: u64, } static LAST_PIN_ADOPT_NS: AtomicU64 = AtomicU64::new(0); @@ -330,39 +259,23 @@ pub mod confirm_load_stats { ns: NS.swap(0, Ordering::Relaxed), blocks: BLOCKS.swap(0, Ordering::Relaxed), utxo_parents: UTXO_PARENTS.swap(0, Ordering::Relaxed), - creates: CREATES.swap(0, Ordering::Relaxed), parent_unique: PARENT_UNIQUE.swap(0, Ordering::Relaxed), pin_cache_body: PIN_CACHE_BODY.swap(0, Ordering::Relaxed), pin_plan: PIN_PLAN.swap(0, Ordering::Relaxed), pin_new: PIN_NEW.swap(0, Ordering::Relaxed), pin_body_ns: PIN_BODY_NS.swap(0, Ordering::Relaxed), - pin_new_meta_ns: PIN_NEW_META_NS.swap(0, Ordering::Relaxed), plan_pin_ns: PLAN_PIN_NS.swap(0, Ordering::Relaxed), - pin_adopt_ns: PIN_ADOPT_NS.swap(0, Ordering::Relaxed), pin_range_fill_ns: PIN_RANGE_FILL_NS.swap(0, Ordering::Relaxed), pin_recent_outs_ns: PIN_RECENT_OUTS_NS.swap(0, Ordering::Relaxed), pin_contract_ns: PIN_CONTRACT_NS.swap(0, Ordering::Relaxed), - pin_publish_ns: PIN_PUBLISH_NS.swap(0, Ordering::Relaxed), cold_io_ns: COLD_IO_NS.swap(0, Ordering::Relaxed), cold_range_ns: COLD_RANGE_NS.swap(0, Ordering::Relaxed), cold_range_n: COLD_RANGE_N.swap(0, Ordering::Relaxed), cold_range_body_ns: COLD_RANGE_BODY_NS.swap(0, Ordering::Relaxed), cold_range_decode_ns: COLD_RANGE_DECODE_NS.swap(0, Ordering::Relaxed), - cold_idx_ns: COLD_IDX_NS.swap(0, Ordering::Relaxed), - cold_idx_n: COLD_IDX_N.swap(0, Ordering::Relaxed), - cold_decode_ns: COLD_DECODE_NS.swap(0, Ordering::Relaxed), - cache_hits: PARENT_CACHE_HITS.swap(0, Ordering::Relaxed), body_tx: BODY_TX_READS.swap(0, Ordering::Relaxed), - parent_tx: FULL_TX_READS.swap(0, Ordering::Relaxed), - missing: MISSING_PARENTS.swap(0, Ordering::Relaxed), - header_ns: HEADER_NS.swap(0, Ordering::Relaxed), - body_decode_ns: BODY_DECODE_NS.swap(0, Ordering::Relaxed), thin_ns: THIN_NS.swap(0, Ordering::Relaxed), parent_pin_ns: PARENT_PIN_NS.swap(0, Ordering::Relaxed), - cache_put_ns: CACHE_PUT_NS.swap(0, Ordering::Relaxed), - edge_same_batch: EDGE_SAME_BATCH.swap(0, Ordering::Relaxed), - edge_fk: EDGE_FK.swap(0, Ordering::Relaxed), - edge_coinbase: EDGE_COINBASE.swap(0, Ordering::Relaxed), } } @@ -381,24 +294,13 @@ pub mod confirm_load_stats { } add!(blocks, BLOCKS); add!(utxo_parents, UTXO_PARENTS); - add!(creates_registered, CREATES); add!(parent_unique, PARENT_UNIQUE); add!(pin_cache_body, PIN_CACHE_BODY); add!(pin_new, PIN_NEW); add!(pin_body_ns, PIN_BODY_NS); - add!(pin_new_meta_ns, PIN_NEW_META_NS); - add!(parent_cache_hits, PARENT_CACHE_HITS); - add!(full_tx_reads, FULL_TX_READS); add!(body_tx_reads, BODY_TX_READS); - add!(missing_parents, MISSING_PARENTS); - add!(header_ns, HEADER_NS); - add!(body_decode_ns, BODY_DECODE_NS); add!(thin_ns, THIN_NS); add!(parent_pin_ns, PARENT_PIN_NS); - add!(cache_put_ns, CACHE_PUT_NS); - add!(edge_same_batch, EDGE_SAME_BATCH); - add!(edge_fk, EDGE_FK); - add!(edge_coinbase, EDGE_COINBASE); } } @@ -1873,15 +1775,6 @@ impl Query { inflight_layers: mem.inflight_layers, inflight_pins: mem.inflight_pins, inflight_bytes: mem.inflight_bytes, - pstore_weak: mem.pstore_weak, - pstore_live: mem.pstore_live, - pstore_bytes: mem.pstore_bytes, - recent_heights: 0, - recent_keys: 0, - recent_pub_keys: 0, - recent_overlay_keys: 0, - recent_fifo_keys: 0, - recent_pin_bytes: 0, h2h_keys, fence_runs: self.store.height_fence_run_count(), bq_promoted: self.block_queue_promoted_count(), diff --git a/crates/rbitcoin-query/src/query_tests.rs b/crates/rbitcoin-query/src/query_tests.rs index df936c8c6..686bcd26f 100644 --- a/crates/rbitcoin-query/src/query_tests.rs +++ b/crates/rbitcoin-query/src/query_tests.rs @@ -275,32 +275,20 @@ fn sampler_stats() { &ConfirmLoadStats { blocks: 1, utxo_parents: 2, - creates_registered: 3, parent_unique: 4, pin_cache_body: 5, pin_new: 6, pin_body_ns: 8, - pin_new_meta_ns: 9, - parent_cache_hits: 10, - full_tx_reads: 11, body_tx_reads: 12, - missing_parents: 13, - header_ns: 14, - body_decode_ns: 15, thin_ns: 16, parent_pin_ns: 17, - cache_put_ns: 18, - edge_same_batch: 19, - edge_fk: 20, - edge_coinbase: 21, - ..Default::default() }, 100, ); let s = confirm_load_stats::sample_and_reset(); assert!(s.ns >= 100); assert!(s.blocks >= 1); - assert!(s.edge_coinbase >= 21); + assert!(s.body_tx >= 12); let _ = archive_phase_stats::sample_and_reset(); archive_phase_stats::note_resolve_counts(1, 2, 3, 4, 5, 6); diff --git a/crates/rbitcoin-store/src/lib.rs b/crates/rbitcoin-store/src/lib.rs index 27644d462..fffb8d73a 100644 --- a/crates/rbitcoin-store/src/lib.rs +++ b/crates/rbitcoin-store/src/lib.rs @@ -115,11 +115,7 @@ pub use scripthash_slabs::{ slab_class_for_packed_len, SH_MEGAKEY_MIN_FKS, }; pub use scripthash_sorted_head::{SortedHead, SortedHeadFilter, SH_SORTED_RECS_PER_PAGE}; -pub use segmented_head::{ - sample_lookup_stats as sample_head_lookup_stats, - snapshot_lookup_stats as snapshot_head_lookup_stats, HeadLookupStats, SegmentedTxHead, - SEGMENT_HEAD_BITS, -}; +pub use segmented_head::{SegmentedTxHead, SEGMENT_HEAD_BITS}; pub use sorted_run::{ commit_run_to_catalog, crc32, detach_run, free_gib_label, host_mem_available_bytes, list_materialize_claims, list_runs, lookup_key, next_run_path, open_run, read_run_body, diff --git a/crates/rbitcoin-store/src/segmented_head.rs b/crates/rbitcoin-store/src/segmented_head.rs index 5f2ab4b69..def966d40 100644 --- a/crates/rbitcoin-store/src/segmented_head.rs +++ b/crates/rbitcoin-store/src/segmented_head.rs @@ -42,45 +42,6 @@ const FLAG_SEALED: u32 = 1; /// Product default head width (2²⁵ slots × 4 B = 128 MiB per segment). pub const SEGMENT_HEAD_BITS: u32 = MAINNET_BITS; -#[derive(Debug, Default, Clone, Copy)] -pub struct HeadLookupStats { - pub open_probes: u64, - pub sealed_fuse_checks: u64, - pub sealed_fuse_skips: u64, - pub sealed_head_probes: u64, - pub rolls: u64, - pub seals: u64, -} - -static LOOKUP_OPEN: AtomicU64 = AtomicU64::new(0); -static LOOKUP_FUSE_CHK: AtomicU64 = AtomicU64::new(0); -static LOOKUP_FUSE_SKIP: AtomicU64 = AtomicU64::new(0); -static LOOKUP_SEALED_PROBE: AtomicU64 = AtomicU64::new(0); -static ROLLS: AtomicU64 = AtomicU64::new(0); -static SEALS: AtomicU64 = AtomicU64::new(0); - -pub fn sample_lookup_stats() -> HeadLookupStats { - HeadLookupStats { - open_probes: LOOKUP_OPEN.swap(0, Ordering::Relaxed), - sealed_fuse_checks: LOOKUP_FUSE_CHK.swap(0, Ordering::Relaxed), - sealed_fuse_skips: LOOKUP_FUSE_SKIP.swap(0, Ordering::Relaxed), - sealed_head_probes: LOOKUP_SEALED_PROBE.swap(0, Ordering::Relaxed), - rolls: ROLLS.swap(0, Ordering::Relaxed), - seals: SEALS.swap(0, Ordering::Relaxed), - } -} - -pub fn snapshot_lookup_stats() -> HeadLookupStats { - HeadLookupStats { - open_probes: LOOKUP_OPEN.load(Ordering::Relaxed), - sealed_fuse_checks: LOOKUP_FUSE_CHK.load(Ordering::Relaxed), - sealed_fuse_skips: LOOKUP_FUSE_SKIP.load(Ordering::Relaxed), - sealed_head_probes: LOOKUP_SEALED_PROBE.load(Ordering::Relaxed), - rolls: ROLLS.load(Ordering::Relaxed), - seals: SEALS.load(Ordering::Relaxed), - } -} - struct Segment { first_fk: u64, count: AtomicU64, @@ -729,7 +690,6 @@ impl SegmentedTxHead { if pass_keys.is_empty() { continue; } - LOOKUP_OPEN.fetch_add(pass_keys.len() as u64, Ordering::Relaxed); let rel_lists = head.probe_fks_batch_ctx(&pass_keys, ctx)?; for (orig_i, rels) in pass_i.into_iter().zip(rel_lists) { for r in rels.into_iter().rev() { @@ -762,13 +722,10 @@ impl SegmentedTxHead { if !key_on(i) { continue; } - LOOKUP_FUSE_CHK.fetch_add(1, Ordering::Relaxed); let fuse_key = fuse_key_from_mixed(m); if !fuse.contains(fuse_key) { - LOOKUP_FUSE_SKIP.fetch_add(1, Ordering::Relaxed); continue; } - LOOKUP_SEALED_PROBE.fetch_add(1, Ordering::Relaxed); pass_i.push(i); pass_keys.push(*m); } @@ -872,7 +829,6 @@ impl SegmentedTxHead { new_list.push(seg); *guard = Arc::new(new_list); } - ROLLS.fetch_add(1, Ordering::Relaxed); rbitcoin_log::info!( "store: tx.head roll open file_id={file_id} first_fk={first_fk} bits={} slots={}", @@ -959,7 +915,6 @@ impl SegmentedTxHead { self.persist_meta_locked()?; let base = segment_head_path(&self.dir, p.file_id); let _ = std::fs::remove_file(&base); - SEALS.fetch_add(1, Ordering::Relaxed); Ok(()) } @@ -1439,43 +1394,6 @@ mod tests { m } - #[test] - fn lookup_stats_sample_and_snapshot_surface() { - // Clear then snapshot zeros; sample swaps to zero again. - let _ = sample_lookup_stats(); - let snap0 = snapshot_lookup_stats(); - assert_eq!(snap0.open_probes, 0); - assert_eq!(snap0.sealed_fuse_checks, 0); - assert_eq!(snap0.sealed_fuse_skips, 0); - assert_eq!(snap0.sealed_head_probes, 0); - assert_eq!(snap0.rolls, 0); - assert_eq!(snap0.seals, 0); - let s = sample_lookup_stats(); - assert_eq!(s.open_probes, 0); - // After create/insert, counters may tick; just ensure API is callable. - let dir = tmp(); - let layout = HeadLayout::with_entry_bytes(10, 4).unwrap(); - let h = SegmentedTxHead::create(&dir, layout).unwrap(); - let mut one = [(mixed(1), Fk(1))]; - h.insert_many(&mut one).unwrap(); - let _ = h.probe_candidates(&mixed(1)).unwrap(); - let snap = snapshot_lookup_stats(); - // At least one of the probe counters should be non-zero after probe. - let any = snap.open_probes - + snap.sealed_fuse_checks - + snap.sealed_fuse_skips - + snap.sealed_head_probes - + snap.rolls - + snap.seals; - let _ = any; - let sampled = sample_lookup_stats(); - let snap_after = snapshot_lookup_stats(); - // sample zeros atomics; snapshot after sample is zero. - assert_eq!(snap_after.open_probes, 0); - let _ = sampled; - let _ = std::fs::remove_dir_all(&dir); - } - #[test] fn migrates_flat_head_layout_on_open() { let dir = tmp(); diff --git a/docs/ibd-memory.md b/docs/ibd-memory.md index eb79349fe..cb11dd625 100644 --- a/docs/ibd-memory.md +++ b/docs/ibd-memory.md @@ -126,7 +126,7 @@ grep 'tip: perf' mainnet.log | `conf loadq=` / `scriptq` / `writeq` | Real queue contents (loadq cap **14**) + pipeline-wide `parents=` + feed ready/inflight | | `txhead` | Segmented `tx.head.*` (open head + sealed heads/fuses; logical sizes) | | `sh` | SH catalog runs / tip heads | -| `heap … iflight= pstore= recent= h2h= fence= fuse8= mphf_g= open_keys= class_c_l2= accounted= residual=` | Approx process heap: BQ + load-ahead CreatePins (`iflight=`) + **pstore/recent meters stay 0** (no process pin store, no RecentCreates ring) + `height_by_hash` + height fence (`Arc` snapshot for leftover TipOnly — not a 15 MiB memcpy/wave) + confirm wire + **sealed `tx.head` fuse8 fingerprints** + FdOnly BDZ `g` heap (`mphf_g=`, 0 after open) + open-segment fuse-key Vec + Class C L2 images; residual = anon − accounted | +| `heap … iflight= h2h= fence= fuse8= mphf_g= open_keys= class_c_l2= accounted= residual=` | Approx process heap: BQ + load-ahead CreatePins (`iflight=`) + `height_by_hash` + height fence (`Arc` snapshot for leftover TipOnly — not a 15 MiB memcpy/wave) + confirm wire + **sealed `tx.head` fuse8 fingerprints** + FdOnly BDZ `g` heap (`mphf_g=`, 0 after open) + open-segment fuse-key Vec + Class C L2 images; residual = anon − accounted | ## Residual heap audit (872k / ~1.42 B creates) From 2f6c01a03bebe0552ba1eb9cdf171fe83705c8b7 Mon Sep 17 00:00:00 2001 From: "rbitcoin-grok[bot]" Date: Wed, 9 Sep 2026 13:26:14 -0700 Subject: [PATCH 3/3] perf(ibd): drop last-write tip_gc snapshot Write no longer GCs header plans (load-owned). post_commit returned a hard-coded 0 ns that still printed on ibd: confirm write slow. Remove the LastWritePhases field and the INFO token. --- CHANGELOG.md | 9 +++++---- crates/rbitcoin-consensus/src/confirm_run/phases.rs | 10 +++------- crates/rbitcoin-consensus/src/confirm_run/write.rs | 6 ++---- crates/rbitcoin-consensus/src/lib.rs | 5 ----- crates/rbitcoin-net/src/ibd/confirm/mod.rs | 3 +-- 5 files changed, 11 insertions(+), 22 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 0165c4b46..2b968115f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -27,10 +27,11 @@ before 1.0). - **`ibd: perf` / `ibd: sizes` drop never-written meters:** DEBUG no longer prints `recon`/`wire`/`resolve`, `parent_io`, `miss_p`, `cold_idx`, `tip_gc`, `recent_pub`, annotate `pread=`, `spend_mix i=/skip=`, - `pstore`, or always-zero heap `recent=` occupancy. Live lookup / load / - scripts / write stage tokens stay. `write=` is Class A + ensure + - structural + class_c + SH + spend + tweaks + pins + head_sub + - drain_join + dequeue. + `pstore`, or always-zero heap `recent=` occupancy. Slow-batch INFO + `ibd: confirm write slow` also drops `tip_gc=` (write no longer GCs + header plans). Live lookup / load / scripts / write stage tokens stay. + `write=` is Class A + ensure + structural + class_c + SH + spend + + tweaks + pins + head_sub + drain_join + dequeue. ## [0.6.0] — 2026-09-08 diff --git a/crates/rbitcoin-consensus/src/confirm_run/phases.rs b/crates/rbitcoin-consensus/src/confirm_run/phases.rs index f8aaa6830..4045793df 100644 --- a/crates/rbitcoin-consensus/src/confirm_run/phases.rs +++ b/crates/rbitcoin-consensus/src/confirm_run/phases.rs @@ -308,13 +308,13 @@ pub(super) fn class_c_commit( Ok(out) } -/// Returns `(spend_ann_ns, tip_gc_ns)` measured with local `Instant`s. +/// Returns spend-annotate wall ns measured with a local `Instant`. /// /// Pure-write annotate from structural abs+meta jobs (no pin `get_spender_abs`). pub(super) fn post_commit( query: &Query, annotate: &[crate::block::SpendAnnotateJob], -) -> Result<(u64, u64), ConsensusError> { +) -> Result { let t_spent = Instant::now(); if query.spend_index_enabled() && !annotate.is_empty() { let mut abs_edges: Vec<(u64, rbitcoin_primitives::Fk, u32, rbitcoin_primitives::Fk)> = @@ -346,11 +346,7 @@ pub(super) fn post_commit( } let spend_ann_ns = t_spent.elapsed().as_nanos() as u64; confirm_phase_stats::UTXO_APPLY_NS.fetch_add(spend_ann_ns, Ordering::Relaxed); - - // Header-cache GC is load-owned (polls store tip each pack). Write does - // not lock ConfirmParentCache. - let tip_gc_ns = 0u64; - Ok((spend_ann_ns, tip_gc_ns)) + Ok(spend_ann_ns) } pub(super) fn check_bip34(block: &Block, height: u32) -> Result<(), ConsensusError> { diff --git a/crates/rbitcoin-consensus/src/confirm_run/write.rs b/crates/rbitcoin-consensus/src/confirm_run/write.rs index 0230fce28..4cdf1c559 100644 --- a/crates/rbitcoin-consensus/src/confirm_run/write.rs +++ b/crates/rbitcoin-consensus/src/confirm_run/write.rs @@ -237,7 +237,7 @@ pub fn confirm_write_phase( .fetch_add(class_c_join_ns, Ordering::Relaxed); } - let (spend_ann_ns, tip_gc_ns) = post_commit(query, &annotate)?; + let spend_ann_ns = post_commit(query, &annotate)?; Ok(( out, n_blocks, @@ -245,7 +245,6 @@ pub fn confirm_write_phase( struct_ph, class_c_ns, spend_ann_ns, - tip_gc_ns, )) })(); @@ -255,7 +254,7 @@ pub fn confirm_write_phase( if drain_join_ns > 0 { confirm_phase_stats::WRITE_DRAIN_JOIN_NS.fetch_add(drain_join_ns, Ordering::Relaxed); } - let (out, n_blocks, structural_ns, struct_ph, class_c_ns, spend_ann_ns, tip_gc_ns) = overlap?; + let (out, n_blocks, structural_ns, struct_ph, class_c_ns, spend_ann_ns) = overlap?; drain_res.map_err(ConsensusError::from)?; if let Some(fk) = drain_max_fk { query.note_head_drain_fk(fk); @@ -291,7 +290,6 @@ pub fn confirm_write_phase( bip68_ns: struct_ph.bip68_ns, class_c_ns, spend_ann_ns, - tip_gc_ns, tweak_ns, }); Ok(out) diff --git a/crates/rbitcoin-consensus/src/lib.rs b/crates/rbitcoin-consensus/src/lib.rs index 13681642e..fad09f9a0 100644 --- a/crates/rbitcoin-consensus/src/lib.rs +++ b/crates/rbitcoin-consensus/src/lib.rs @@ -207,7 +207,6 @@ pub mod confirm_phase_stats { static LAST_WRITE_BIP68_NS: AtomicU64 = AtomicU64::new(0); static LAST_WRITE_CLASS_C_NS: AtomicU64 = AtomicU64::new(0); static LAST_WRITE_SPEND_ANN_NS: AtomicU64 = AtomicU64::new(0); - static LAST_WRITE_TIP_GC_NS: AtomicU64 = AtomicU64::new(0); static LAST_WRITE_TWEAK_NS: AtomicU64 = AtomicU64::new(0); static LAST_WRITE_WALL_NS: AtomicU64 = AtomicU64::new(0); @@ -226,7 +225,6 @@ pub mod confirm_phase_stats { pub bip68_ns: u64, pub class_c_ns: u64, pub spend_ann_ns: u64, - pub tip_gc_ns: u64, /// BIP-352 thin tweak index (`index_sp_tweaks_batch`) after annotate. pub tweak_ns: u64, } @@ -250,7 +248,6 @@ pub mod confirm_phase_stats { LAST_WRITE_BIP68_NS.store(p.bip68_ns, Ordering::Relaxed); LAST_WRITE_CLASS_C_NS.store(p.class_c_ns, Ordering::Relaxed); LAST_WRITE_SPEND_ANN_NS.store(p.spend_ann_ns, Ordering::Relaxed); - LAST_WRITE_TIP_GC_NS.store(p.tip_gc_ns, Ordering::Relaxed); LAST_WRITE_TWEAK_NS.store(p.tweak_ns, Ordering::Relaxed); } @@ -266,7 +263,6 @@ pub mod confirm_phase_stats { bip68_ns: LAST_WRITE_BIP68_NS.load(Ordering::Relaxed), class_c_ns: LAST_WRITE_CLASS_C_NS.load(Ordering::Relaxed), spend_ann_ns: LAST_WRITE_SPEND_ANN_NS.load(Ordering::Relaxed), - tip_gc_ns: LAST_WRITE_TIP_GC_NS.load(Ordering::Relaxed), tweak_ns: LAST_WRITE_TWEAK_NS.load(Ordering::Relaxed), } } @@ -827,7 +823,6 @@ mod coverage_tests { bip68_ns: 50_000, class_c_ns: 400_000, spend_ann_ns: 300_000, - tip_gc_ns: 10_000, tweak_ns: 2_500_000, }); let p = last_write_phases(); diff --git a/crates/rbitcoin-net/src/ibd/confirm/mod.rs b/crates/rbitcoin-net/src/ibd/confirm/mod.rs index ccba0309b..4eccb23b5 100644 --- a/crates/rbitcoin-net/src/ibd/confirm/mod.rs +++ b/crates/rbitcoin-net/src/ibd/confirm/mod.rs @@ -1462,7 +1462,7 @@ pub(crate) fn spawn_confirm_engine( info!( "ibd: confirm write slow batch={n} parts={parts} first={first_h} wall={:?} \ class_a={}ms ensure={}ms struct={}ms spent={}ms create_h={}ms \ - bip68={}ms class_c={}ms spend_ann={}ms tip_gc={}ms tweaks={}ms", + bip68={}ms class_c={}ms spend_ann={}ms tweaks={}ms", elapsed, ms(p.class_a_ns), ms(p.ensure_ns), @@ -1472,7 +1472,6 @@ pub(crate) fn spawn_confirm_engine( ms(p.bip68_ns), ms(p.class_c_ns), ms(p.spend_ann_ns), - ms(p.tip_gc_ns), ms(p.tweak_ns), ); }