Repository navigation
test: let coverage journeys finish and let Electrum history catch up - #1158
Conversation
![rearden-grok[bot]](https://avatars.githubusercontent.com/u/730881?s=60&v=4){kind=small}
There was a problem hiding this comment.
Summary
Moving note_headers_reply to after apply_headers returns Ok closes the original race on the path that matters: a connecting batch is persisted inside classify_headers (via persist_pending_header_path / note_header_tip) before apply_headers returns, so the wait sees best_header_height ahead of the block tip until the body connects, and sh_is_tip_ready stays false until include_hwm covers the new txs.count(). Early Ok returns (empty, misbehave, non-connecting, below-floor, hopeless disconnect, send-budget) do not store that new tip, so counting them does not replay “batch still in flight.” The success predicate is still not tied to the post-mark follow round: initial_getheaders_sent and headers_reply_count are process-global and not paired, and the only production caller (run.rs around the pre-dial mark) can treat some other headers message as the round while the follow getheaders that carries the new block is outstanding. The 20s and shutdown returns, and the llvm-cov wall scaling, match the code.
Disposition: Comment. No finding should block merge: the height-103 ordering bug is fixed on the connecting reply, and the counter aliasing is a follow-up that does not by itself undo that path.
Issue counts by severity
- bugs: 1
- suggestions: 3
- nits: 0
| let tip = node.tip_height().unwrap_or(0); | ||
| let best = node.hub.best_header_height(); | ||
| let sh_ok = !shindex || node.hub.query.sh_is_tip_ready(); | ||
| if sent > 0 && replies >= sent && best <= tip && sh_ok { |
There was a problem hiding this comment.
[bug] Disposition: follow-up. sent > 0 && replies >= sent does not mean the post-materialize follow getheaders has been applied. The only production caller snapshots both atomics before the follow dials (header_mark just above wait_wallet_history), then requires only that later initial_getheaders_sent deltas are matched by later headers_reply_count deltas. Those counters are not a pair: note_initial_getheaders_sent runs only from maybe_queue_initial_getheaders, while note_headers_reply runs for every on_headers that returns Ok. A headers message that does not advance best_header_height (empty, already-known, non-connecting, or not stored) therefore satisfies the predicate while sh_is_tip_ready is still true for the pre-dial tip. That message can be a reply to a getheaders counted in the pre-dial snapshot (inbound accept and --connect hostname redial are live through materialize, and peer_session_with sends the initial getheaders at session start) or a getheaders that never increments the sent counter (on_headers_poll calls queue_getheaders with mark_awaiting false; inv and compact-block paths do the same). One such reply plus one still-unanswered follow send makes replies >= sent and the wait returns before the round that carries the new block is applied. Two post-mark initial sends do not have this hole by themselves, because an empty reply from one peer does not fill the quota of the peer that still has the block.
Suggestion: Retire a specific in-flight follow round (a generation bumped when the post-mark dials call maybe_queue_initial_getheaders, or one outstanding token per follow session) instead of comparing the two global totals. Do not let poll, inv, continuation, or pre-mark replies decrement that generation unless they are the response to that send. Keep best <= tip and sh_is_tip_ready as they are; they already hold the wait once the new header is actually stored.
There was a problem hiding this comment.
The bind no longer compares those two totals. Each initial getheaders gets an id when it is sent, and that id stays open until the headers message from that same peer has been applied. A headers message from any other peer does not close it. If the reply contains a new block, the header tip and the scripthash check still hold Electrum until the block is connected and the index covers it. Shutdown and the 20 second deadline still open the bind.
| @@ -0,0 +1,3 @@ | |||
| Fixed | |||
|
|
|||
| - **Electrum stays down until the follow headers round is indexed.** A block mined while scripthash materialize runs is no longer missing from the first history answer. The bind waits until that `getheaders` has been applied and the scripthash head covers the tip, not merely until the message is counted or two seconds have passed. | |||
There was a problem hiding this comment.
[suggestion] Disposition: follow-up. The note says the bind waits until that follow getheaders has been applied and the scripthash head covers the tip, and that a block mined during materialize is no longer missing. apply_headers returning Ok does not index scripthash on any path; indexing is only the separate sh_is_tip_ready check, and only for the store tip at poll time. Combined with the global reply count, an Ok headers message that never stored the new block still meets the written claim, so “indexed” and “no longer missing” overclaim what the predicate guarantees.
Suggestion: Describe the wait as “a post-dial initial getheaders reply has been applied, the header tip is not ahead of the block tip, and the scripthash head covers that tip,” and drop the absolute “no longer missing” unless the counter is actually tied to that round.
There was a problem hiding this comment.
Rewrote the note. It now says the bind waits until each initial getheaders sent after the follow dials has been applied, the header tip is not ahead of the block tip, and the scripthash head covers that tip. It no longer says apply indexes the block, or that the mined coinbase can no longer be missing.
| .await?; | ||
| apply_headers(apply, hub, out_tx, follow, session) | ||
| apply_headers(apply, hub, out_tx, follow, session)?; | ||
| // Counting this before apply let the wallet bind finish the round |
There was a problem hiding this comment.
[suggestion] Disposition: optional. The comment restates the old failure (the wallet bind finishing and Electrum serving the old tip) instead of the invariant that makes this line correct. The store of a connecting batch happens in classify_headers before apply_headers is even called, so “before apply” / “still in flight” is bug history, not why this call sits here.
Suggestion: Replace it with one line that the reply count must not move until apply_headers has returned, because the wallet wait treats the count as the batch being done.
There was a problem hiding this comment.
Replaced that comment. It now says the wallet wait treats a retired id as this batch being done, which is why the id is cleared only after apply returns.
| node.follow_live.fetch_add(1, Ordering::SeqCst); | ||
| let shutdown = Shutdown::new(); | ||
| let pending = { | ||
| let mut wait = std::pin::pin!(wait_wallet_history(&node, true, &shutdown, (0, 0))); |
There was a problem hiding this comment.
[suggestion] Disposition: optional. wallet_history_stays_down_until_getheaders_or_shutdown only checks that a (0, 0) mark and follow_live > 0 do not return for 2.5s, then that shutdown unblocks. It never delivers a headers message, so it cannot fail if note_headers_reply moves back ahead of apply_headers, and it cannot see a non-advancing reply filling replies >= sent while a later batch is unapplied. The removed 2s unsent escape is what this test pins.
Suggestion: Add a net-level case that counts the reply only after a connecting header is visible to best_header_height, and a node-level case where one post-mark note_headers_reply without a new header tip does not satisfy a still-outstanding post-mark send.
There was a problem hiding this comment.
Added two tests. The node test opens an initial getheaders id, counts an unrelated headers reply, and checks the bind stays down until that id is retired. The net test sends headers from a different peer and checks the asked session stays open, then sends that session a connecting header and checks the header is stored and still ahead of the connected tip when the id is retired. The original test still pins the removed two-second escape.
There was a problem hiding this comment.
Summary
Electrum no longer binds on the two-second unsent escape, and a headers reply is counted only after apply_headers returns. A connecting batch is persisted in classify_headers before that count, and best_header_height stays above the block tip until the body is connected, so the pre-dial tip cannot satisfy sent > 0 && replies >= sent && best <= tip && sh_is_tip_ready on the path this PR closes. Non-storing Ok returns still increment headers_replies, but they do not reopen that path by themselves. The real gap is test-only: under llvm-cov the invalid-heavier outer wall is shorter than its serial sync budgets.
Disposition: Comment. The coverage-wall mismatch should be fixed, but it does not undo the connecting-reply wait and should not block merge.
Issue counts by severity
- bugs: 1
- suggestions: 2
- nits: 0
| let addrs: Vec<NetAddr> = peers.iter().copied().map(NetAddr::Ip).collect(); | ||
| tokio::time::timeout( | ||
| Duration::from_secs(20), | ||
| llvm_cov_wall(20, 60), |
There was a problem hiding this comment.
[bug] Disposition: follow-up. sync_to now waits up to 60s when CARGO_LLVM_COV is set, and invalid_heavier_fork_journey calls it five times in series (valid prefix, heavier honest, restart, restart with only honest, and fork at the invalid block) inside the 180s llvm-cov wall at end_of_ibd_invalid_heavier_fork. Those budgets sum to 300s, so the outer timeout can fire while every sync is still inside the limit this change adds. Before this diff each sync was a fixed 20s (100s total), which fit in 180s. The default 20s branch is unchanged and still does not fit in the 60s default wall; that part is not new.
Suggestion: Raise that journey wall to at least five times 60s plus start and shutdown slack, and match the llvm figure in TESTING.md. Otherwise share one deadline so the sum of the inner budgets cannot exceed the outer one.
There was a problem hiding this comment.
The coverage wall for this journey is now 360 seconds, which covers five 60-second syncs plus startup. The uninstrumented outer wall is still 60 seconds, and each uninstrumented sync is still 20 seconds. TESTING.md matches that.
| node.follow_live.fetch_add(1, Ordering::SeqCst); | ||
| let shutdown = Shutdown::new(); | ||
| let pending = { | ||
| let mut wait = std::pin::pin!(wait_wallet_history(&node, true, &shutdown, (0, 0))); |
There was a problem hiding this comment.
[suggestion] Disposition: optional. wallet_history_stays_down_until_getheaders_or_shutdown only checks that a follow-live node marked (0, 0) stays pending for 2.5s and then returns on shutdown. It never delivers a headers message, so putting note_headers_reply back ahead of apply_headers still passes. The tiny store also makes sh_is_tip_ready false (tip_max == 0), so the success predicate is not what holds the wait.
Suggestion: Feed one connecting headers batch through on_headers and assert the wait stays pending until that header is connected and the scripthash head covers it. A count bumped before apply_headers should fail the test.
There was a problem hiding this comment.
The new node test turns the scripthash requirement off, so an empty store cannot hide a false success. It counts an unrelated headers reply and checks the bind stays down until the follow id is retired. The net test delivers a real connecting header from the asked peer and checks that header is still ahead of the connected tip when the round ends.
| .await?; | ||
| apply_headers(apply, hub, out_tx, follow, session) | ||
| apply_headers(apply, hub, out_tx, follow, session)?; | ||
| // Counting this before apply let the wallet bind finish the round |
There was a problem hiding this comment.
[suggestion] Disposition: optional. The new comment narrates the old bug (the reply was counted before apply, and Electrum then served the old tip) instead of a constraint that is still true of this code.
Suggestion: Delete it, or say only that the wallet wait treats this counter as "apply returned" and that the increment has to stay below apply_headers.
There was a problem hiding this comment.
Replaced that comment. It now says the wallet wait treats a retired id as this batch being done, which is why the id is cleared only after apply returns.
There was a problem hiding this comment.
Summary
A headers batch retires only the awaiting session's id, and only after apply_headers returns Ok, so another peer's headers cannot finish the round and an empty, misbehaving, or below-floor reply retires an id only when it is that session's own in-flight response. The new wait still treats sent > 0 && open == 0 as "every post-dial initial getheaders has been applied." That is false while a later follow session has not published an id yet, and it is also false in the gap where the sent counter is bumped before the id is pushed. Either one opens Electrum on the pre-dial tip, which is the miss this change is closing.
Disposition: Comment. The unpublished-id success path should block merge.
Issue counts by severity
- bugs: 2
- suggestions: 0
- nits: 0
| return; | ||
| } | ||
| if sent == 0 && started.elapsed() >= unsent_limit { | ||
| if sent > 0 && open == 0 && best <= tip && sh_ok { |
There was a problem hiding this comment.
[bug] Disposition: block. sent > 0 && open == 0 becomes true as soon as every id published so far has been retired, which is not the same as every follow session dialed in this loop having applied its initial getheaders. follow_from_net_as returns after handshake and tokio::spawn; maybe_queue_initial_getheaders runs only later in peer_session_with, after the SendHeaders / SendCmpct / ping / feefilter awaits. The dial loop awaits those handshakes one at a time, so the first session runs during the later handshakes. A peer that does not have the block mined during materialize answers the locator with an empty headers message, on_headers retires that id, and best <= tip plus sh_is_tip_ready still describe the pre-dial tip. wait_wallet_history then checks the predicate on the same task turn as the last spawn, before that session reaches note_initial_getheaders_sent. The wait returns and start_electrum_if_ready binds on the old history. With one follow peer this particular schedule does not fire (sent stays 0 until that peer notes); with two or three it is the ordinary empty reply from the faster peer.
Suggestion: Publish each follow session's id before follow_from_net_as returns, and do not let the wait succeed until every session spawned for this dial loop has either retired that id or failed to start headers sync. An empty reply from a peer that already matched the pre-dial locator must not satisfy the predicate while a sibling session is not in the outstanding set yet.
There was a problem hiding this comment.
Each follow dial now publishes its headers round when the handshake finishes, before that session is scheduled. The bind stays down until every one of those rounds has been applied, or that peer will not send getheaders, and until a queued follow dial has finished its handshake. A peer that is not the headers-sync peer drops its round right away, so the bind does not sit for the full 20 seconds. This is f06b052, on top of the lock change in fff8c44.
| pub fn note_initial_getheaders_sent(&self) -> u64 { | ||
| let id = self | ||
| .initial_getheaders_sent | ||
| .fetch_add(1, Ordering::Relaxed) |
There was a problem hiding this comment.
[bug] Disposition: follow-up. note_initial_getheaders_sent publishes the new count with fetch_add before it pushes the id. wait_wallet_history reads that count and then locks the outstanding vec. If the noting task is preempted after the add, or the wait task runs between the add and the push, sent > 0 and open == 0 at the same time, while best <= tip and the scripthash head still match the pre-dial tip. The wait returns before that getheaders exists. The mutex does not close the gap, because the counter read is outside it. This is the single-peer form of the same early open; the dial-loop hole above does not depend on it.
Suggestion: Increment the counter and push the id while holding outstanding_initial_getheaders, and read both under that same lock in the wait. There should be no observable state where the count has moved and the id is absent.
There was a problem hiding this comment.
The sent count and the id are stored while holding the same lock, and the bind reads the count, the open ids, and any dial that has not finished its handshake under that lock. That is fff8c44.
c80ef21 to
f06b052
Compare
niteshbalusu11
left a comment
niteshbalusu11
left a comment
There was a problem hiding this comment.
This fixes #1185. Locally, I ran 16 parallel copies of end_of_ibd_sh_interrupt. On master 8e62e4ce, 2 of 80 runs failed with "Electrum opened before script A history was complete". In both, Electrum bound 1–5 ms before p2p: headers sync height=103. At f06b052d, 240 of 240 runs passed.
Three gaps at f06b052d. I traced each by hand. GPT-6 Astra found them in review.
1. A queued follow dial does not hold the bind. run.rs:2252
On the dial_failed_all() path, startup calls begin_follow_arm() and queues the dial. Then wait_wallet_history returns at once on follow_live_count() == 0. follow_live goes up only after the handshake (service.rs:758), so pending is never read on this path. Scenario: a node with an indexed tip at 102 restarts while the miner is briefly down. catch_up_after_err returns complete_dial_failed(). Electrum binds at 102, and the retried dial then finds 103. Master does the same, so this is not a regression. The new arm code and its comment do not do what they say, though. wallet_history_stays_down_while_a_follow_arm_is_pending misses this because it sets follow_live to 1 by hand.
2. A failed header batch leaks its round id. peer.rs:4175-4193
on_headers swaps the id out of the session before run_header_job(..).await? and apply_headers(..)?. It retires the id only when both return Ok. On an error, the hub keeps the id, and teardown at service.rs:793 reads 0. Scenario: the peer sends invalid headers in reply to the initial getheaders, or the writer closes while classify runs. The bind then waits the full 20 s, even if another peer connects 103. This delays Electrum. It does not open it early.
3. Aborted and inbound sessions do not retire their ids. service.rs:793, service.rs:593
The retire after peer_session_with(..).await does not run when the task is aborted (disconnect_id, eviction). An inbound session also gets an id through maybe_queue_initial_getheaders, and its teardown never retires it. Either way the bind waits out the 20 s deadline, and ids pile up after startup. A drop guard that owns the id from arm time would cover abort and both directions.
Also: headers_replies no longer has a production reader.
I'd fix 1 before merge. 2 and 3 only delay Electrum and could be a follow-up.
The stall-disconnect wait and the long addrfetch completion expired on coverage while the uninstrumented run stayed inside its budgets. Those two waits and the outer wall scale by the same factor as the other P2P journeys when CARGO_LLVM_COV is set.
Five serial syncs each get 60s under coverage, and the journey wall is 360s so those syncs fit.
Electrum can open on the indexed tip while a block mined during materialize is still on the way. The journey polls until that history and the RPC tip match, instead of requiring both at the moment the port opens.
f06b052 to
4d945b9
Compare
rearden-grok
Bot
changed the title
|
Dropped the Electrum hold. Starting with Electrum behind the tip is acceptable, and the brief mempool-to-confirmed gap stays in #1162. The branch is three test commits. The scripthash journey polls until history and the RPC tip match the miner, instead of treating the moment the port opens as a finished tip. The getaddr and invalid-heavier journeys only get more time under coverage. The round-id, pending-dial, and reply-counter machinery is gone, so the three bookkeeping gaps on the old head no longer apply. |
Summary
Coverage was failing on journeys the
testjob already passed. Electrum is allowed to bind on the indexed tip while a follow headers round is still bringing a newer block in. The steady-state gap, where a transaction is in neither the mempool nor the confirmed index for a moment, stays in #1162.end_of_ibd_sh_interruptpolls until Electrum history and the RPC tip match the miner, instead of requiring that match at the moment the Electrum port opens.p2p_timeout_getaddr_and_keepalive_pingscales its stall-disconnect wait (15s → 45s), long-addrfetch completion (3s → 9s), and outer wall (20s → 60s) underCARGO_LLVM_COV.end_of_ibd_invalid_heavier_forkscales each sync (20s → 60s) and the journey wall (180s → 360s) the same way. Uninstrumented budgets are unchanged.No production code changes.
#1185 is this journey failing in
testandcoveragewithElectrum opened before script A history was complete: Electrum had returned 103 txids and the fixture wanted 104, the coinbase mined while the index was materializing. The failingassert_eq!is gone. Aftermine_one_a, the poll keeps reading until script A contains that txid, script B matches, andgetblockcount/getbestblockhashmatch the miner. A history that stays short fails at the poll deadline with both counts. A short first read, which is the #1185 flake, waits and reads again.Fixes #1185.
Test plan
cargo test -p rbitcoin-test --test suite end_of_ibd_sh_interrupttestandcoverageon4d945b989