fix(dash-spv): promote finished header segments from the tick, not only on a message - #960
Conversation
…ly on a message
A testnet wallet restore froze with the whole chain downloaded and none
of the tail of it stored:
Headers: Syncing 2520289/2520288 (100.0%) processed: 1274000, buffered: 1046289
Filter Headers: Syncing 1474000/2520288 (58.5%)
Blocks: WaitForEvents last_relevant: 1472978
Peers stayed connected and chain locks kept arriving for the sixteen
minutes the app was left running afterwards. Nothing advanced again.
`processed`/`buffered` decode as 1,474,000 headers in storage and
1,046,289 more downloaded, validated and held in memory. The top line
reads 100% because `current_height()` is `tip + buffered` — it counts
what was downloaded, not what was kept.
`take_ready_to_store` is the only thing that promotes a finished segment
into storage, and its single caller was `handle_headers_pipeline` —
reached only when a `Headers` message arrives. All 47 checkpoint
segments had finished downloading by 22:23:12, so no further `Headers`
would ever come and the promotion had nothing left to trigger it. Filter
headers, filters and blocks then coasted to a stop over the next four
minutes as they consumed the backlog they had been racing ahead on,
which is what made the stall visible at 22:27:20.
`tick` runs every 100ms and called only `handle_timeouts` and
`send_pending`. It now takes, refills and stores in the same order
`handle_headers_pipeline` uses — #950 established that ordering so a
segment exposed by draining gets requested in the same pass — and
finalizes if that was the last of the work.
`store_ready_batches` and `finalize_sync_if_complete` are lifted out of
`handle_headers_pipeline`, which still calls both in place. The drain
itself stays at the call sites rather than moving into the helper,
precisely so the take → refill → store order is preserved on both paths.
No behaviour change on the message-driven path.
**Not established:** why the first promotion opportunity — the message
that completed segment 25 — stored nothing. No error is logged anywhere
near it and no early return in the current code fits the evidence. This
lets the pipeline recover from that miss; it does not explain the miss.
Worth a `RUST_LOG=dash_spv::sync::block_headers=trace` reproduction.
#950's `ACTIVE_SEGMENT_WINDOW` narrows the blast radius — at most eight
segments' worth of headers strand instead of a million — but adds no
trigger for promotion, so the stall survives it.
The regression test covers both halves: a tick promotes buffered headers
with no further message, and a tick over a complete pipeline announces
the sync. It fails without the change at the promotion assertion.
cargo test -p dash-spv --lib # 547 passed
cargo test -p dash-spv --test header_dispatch_order # passed
cargo clippy --all-targets + cargo fmt --check # clean
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (2)
📝 WalkthroughWalkthroughThe header sync manager now stores buffered header batches and finalizes completed initial syncs during ChangesHeader sync completion
Estimated code review effort: 3 (Moderate) | ~25 minutes Mergeability Score: ⚪ Minimal · up to This localized change promotes completed header work during periodic processing and includes focused and broader validation; no actionable merge-blocking risk remains beyond normal checks and review. Sequence Diagram(s)sequenceDiagram
participant SyncManagerTick
participant BlockHeadersManager
participant RequestSender
SyncManagerTick->>BlockHeadersManager: drain and store ready batches
SyncManagerTick->>RequestSender: send pending header requests
SyncManagerTick->>BlockHeadersManager: finalize sync if complete
BlockHeadersManager-->>SyncManagerTick: storage and completion events
Possibly related PRs
Suggested labels: Suggested reviewers: 🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## dev #960 +/- ##
=======================================
Coverage 76.47% 76.48%
=======================================
Files 329 329
Lines 80353 80403 +50
=======================================
+ Hits 61453 61495 +42
- Misses 18900 18908 +8
|
ZocoLini
left a comment
ZocoLini
left a comment
There was a problem hiding this comment.
Are you able to create an integration test that recreates the same issue??
|
I tried, and I want to give you a straight answer rather than a hopeful one: not one that reproduces the original stall, no — and the reason is worth stating because it also bounds what this PR claims. What blocks a
|
|
@xdustinface can you take a look into this pls?? |
…a header event (#964) * fix(dash-spv): extend the CFHeaders queue from the tick, not only on a header event `handle_new_headers` is the only thing that ever extends the filter-header queue, and it runs solely off `BlockHeaderSyncComplete` and `BlockHeadersStored`. Block-header storage can advance without either reaching this manager: a segment completing out of order promotes a run of buffered headers, and on a long scan that is how the last stretch of the chain lands. When that happens the manager keeps the target it was last told about, its queue drains, and nothing re-arms it. Filter headers then stop for good while block headers, ChainLocks and inv announcements carry on — so the client looks alive while sync is frozen, which is what makes this hard to spot from the outside. Observed on a mainnet restore: the queue was last extended to height 2_398_000 at 19:12:58, block headers reached 2_523_515 at 19:36:48, and filter headers never moved again — filters and blocks stuck at 95% with `last_activity` climbing past twenty minutes. The tick now re-reads the tip from storage and calls `handle_new_headers` when it has moved past what this manager knows. Same shape as promoting finished header segments from the tick (#960): trust the tick, not the message. The regression test drives exactly that sequence — storage advances with no event delivered — and fails without this change. * style(dash-spv): sort the test module's imports as rustfmt wants * test(dash-spv): assert the tick actually queues CFHeaders, not just the tip The tip assertion alone was too weak to protect the fix. `handle_new_headers` updates `block_header_tip_height` before it touches the pipeline, so a version that noticed the advance and then queued nothing would still have passed — and would have left sync exactly as frozen as the bug it is meant to close. The test now drains the request channel and requires at least one `GetCFHeaders`, then checks every stop hash against the headers in the newly discovered range, so a request rebuilt from the stale target cannot satisfy it either. Still falsifiable: with the tick branch removed the test fails, now on the tip assertion first. --------- Co-authored-by: Roman <51091564+jeanpierreroma@users.noreply.github.com>
3 participants
The stall
A testnet wallet restore froze with the whole chain downloaded and none of the tail of it stored:
Peers stayed connected and
ChainLockReceivedkept arriving for the sixteen minutes the app was left running afterwards.PeersUpdatednever reportedconnected=0— this is not a disconnect path.processed/buffereddecode as 1,474,000 headers in storage and 1,046,289 more downloaded, validated and held in memory. The top line reads 100% becausecurrent_height()istip + buffered: it counts what was downloaded, not what was kept.Why it cannot recover
take_ready_to_storeis the only thing that promotes a finished segment into storage, and its single caller ishandle_headers_pipeline— reached only when aHeadersmessage arrives.All 47 checkpoint segments finished downloading by 22:23:12 (segment 25 last). From that instant no further
Headerswould ever arrive, so the promotion had nothing left to trigger it.tick, which runs every 100ms, called onlyhandle_timeoutsandsend_pending.Filter headers, filters and blocks then coasted to a stop over the next four minutes as they consumed the backlog they had been racing ahead on — which is why the symptom looks like it starts at 22:27:20 rather than 22:23:12.
The change
ticknow takes, refills and stores in the same orderhandle_headers_pipelineuses, then finalizes if that was the last of the work.The ordering is deliberate and follows #950: draining can expose a segment at the end of the active window, and the refill should pick it up in the same pass. That is also why
store_ready_batchestakes the batches rather than draining them itself — movingtake_ready_to_storeinside the helper would have forced the refill after the storage writes on both paths.store_ready_batchesandfinalize_sync_if_completeare lifted out ofhandle_headers_pipeline, which still calls both in place. No behaviour change on the message-driven path.Relationship to #950
ACTIVE_SEGMENT_WINDOWnarrows the blast radius — at most eight segments' worth of headers strand instead of a million — but adds no trigger for promotion, so the stall survives it. I rebased ontodevafter #950 landed and confirmed the gap is still there:tick'sSyncingarm is byte-for-bytehandle_timeouts+send_pending+return Ok(vec![]).What this does not explain
Why the first promotion opportunity — the message that completed segment 25 — stored nothing. No error is logged anywhere near it, and no early return in the current code fits the evidence. This lets the pipeline recover from that miss; it does not explain the miss. A
RUST_LOG=dash_spv::sync::block_headers=tracereproduction would settle it, and I would rather ship the self-healing path than block on the trigger, since the same missed promotion is unrecoverable today whatever causes it.Test
test_tick_promotes_buffered_headers_with_no_further_messagescovers both halves: a tick promotes buffered headers when no further message will arrive, and a tick over a complete pipeline announces the sync rather than leaving the manager inSyncing. It fails without the change, at the promotion assertion.Relationship to #955
Independent — different subsystem, different files, no shared commits, both branch from
dev. #955 fixes an assert reachable through the filters manager; this fixes a header-pipeline stall. They were briefly one PR and were split so neither waits on the other.Also worth someone's eye, found while tracing this and not addressed here:
headers2_stateis a singleCompressionStateshared across all peer connections (network/manager.rs:512) rather than one per peer, and the run logged 36 ×Received 8000 headers with prev_hash … but no segment matched. The segment-25 batch passed its checkpoint hash check so it was genuine data, but interleavedHeaders2streams from multiple peers look like a real decompression hazard.Summary by CodeRabbit