IPC stability bugs

Bug 54

IPC functional test checks a second node before the block reaches it

Status
Fixed
Symptom
Assertion failure; worst effect seen: test failure only
Where seen
Bitcoin Core functional tests
Trigger
Normal use; no special event is needed
First reported
2025-11-15 (first report)
Fixed
2025-11-20
Fix
bitcoin#33880

Summary

The interface_ipc.py functional test failed intermittently in CI at its "Block should propagate" check, because it asserted the second node's tip height right after submitSolution returned on the first node, before the block had been relayed. The defect was in test code and did not affect users. Fixed by bitcoin#33880 ("test: Fix race condition in IPC interface block progation test").

What happened

Three days after bitcoin#33745 (which fixed a stale witness-commitment check in submitSolution and extended this test) merged, interface_ipc.py started failing on the CI runs of unrelated PRs (bitcoin#33856, bitcoin#33878). @fjahr opened bitcoin#33880 from the bitcoin#33878 CI log on 2025-11-15, and @yuvicc independently filed bitcoin#33884 ("interface_ipc functional test failing in CI") the next morning, noting that the test failed in CI but passed locally.

Root cause

bitcoin#33745, in commit 862bd432837e, extended the submitSolution test in test/functional/interface_ipc.py with

assert_equal(self.nodes[1].getchaintips()[0]["height"], current_block_height + 1)

immediately after submitSolution returned True on node 0, and only then called self.sync_all(). submitSolution returns once node 0 has accepted the block; the block still has to be relayed to node 1 over the P2P connection, so on a loaded CI runner node 1's tip could still be at the old height when the assertion ran.

The code

Quoted from 2578e6fc0f4a^. The submitSolution test in test/functional/interface_ipc.py submits a block to node 0 over IPC and then immediately checks node 1's tip:

self.log.debug("Submit again, with the witness")
res = await template.result.submitSolution(ctx, block.nVersion, block.nTime, block.nNonce, coinbase.serialize())
assert_equal(res.result, True)

self.log.debug("Block should propagate")
assert_equal(self.nodes[1].getchaintips()[0]["height"], current_block_height + 1)
# Stalls if a regression causes submitBlock() to accept an invalid block:
self.sync_all()
assert_equal(self.nodes[0].getchaintips()[0], self.nodes[1].getchaintips()[0])

submitSolution returns once node 0 has processed the block; nothing waits for it to reach node 1:

  1. Node 0: submitSolution connects the block and returns True.
  2. Test: nodes[1].getchaintips() runs while the block is still being relayed over P2P, and on a slow CI runner still reports the old height.
  3. Test: the assert_equal fails before sync_all() would have waited for node 1.

The fix checks node 0 before syncing and leaves node 1 to the comparison after sync_all() (2578e6fc0f4a):

@@ -256,9 +256,11 @@ class IPCInterfaceTest(BitcoinTestFramework):
             self.log.debug("Block should propagate")
-            assert_equal(self.nodes[1].getchaintips()[0]["height"], current_block_height + 1)
+            # Check that the IPC node actually updates its own chain
+            assert_equal(self.nodes[0].getchaintips()[0]["height"], current_block_height + 1)
             # Stalls if a regression causes submitBlock() to accept an invalid block:
             self.sync_all()
+            # Check that the other node accepts the block
             assert_equal(self.nodes[0].getchaintips()[0], self.nodes[1].getchaintips()[0])

Node 0's tip is already updated when submitSolution returns, and node 1 is only compared after sync_all() has waited for the block to arrive, so neither check depends on relay timing.

Fix

Commit 2578e6fc0f4a checks node 0's tip height before the sync instead (the IPC node must update its own chain), and keeps sync_all() plus the comparison of both nodes' tips as the propagation check (+3/-1). @Sjors explained in review why both checks are needed: relying on sync_all() alone would miss a regression where the IPC node fails to connect the block at all, since both nodes would then stay in sync.

Timeline

Lessons

What would have prevented this bug, found it sooner, or made it easier to debug. The patterns page groups these lessons across all bugs.

Pattern Test timing, and tests that cannot fail: A test that assumes timing

  • Prevented by a review checklist item
  • Earliest detector code review (existed then)
  • Diagnosis easy
  • Fix design easy
  • Debugging aids CI artifacts
  • Rust no

Would Rust have prevented it? No. A test asserting on a second node before waiting for propagation is a timing assumption in the test, unrelated to the implementation language. More on Rust

Could it have been prevented?

Yes, by the functional-test framework's own convention: a check on a node other than the one an action was performed on goes after sync_all() or a wait_until, never between the action and the sync. The added line asserted node 1's tip height straight after submitSolution returned on node 0, then synced. The intent was a stronger property (the IPC node connected the block itself, not just that the two nodes agree), and the fix keeps that intent by asserting on node 0 before the sync and on node 1 after it. The review of bitcoin#33745 focused on the validation fix, which is where the risk seemed to be; the test hunk was a few lines and passed locally, where P2P relay between two regtest nodes wins the race almost always.

Could it have been found sooner?

By review of the test hunk, which is the only check cheaper than what happened. CI found it three days after merge, on two unrelated PRs, and that is close to the floor for an intermittent failure that never fires on a developer machine. Running new functional tests under CI-like load before merge is not a check the project has, and the same race would have been invisible in a single-node test.

What made it hard to debug?

Nothing. The CI log named the failing assertion and the expected versus actual height, and the difference between "fails in CI, passes locally" and the missing sync was the whole diagnosis; fjahr opened the fix from the log the same evening, and the only review discussion was Sjors's point that dropping the pre-sync check would lose the regression coverage the line was added for.

Lesson

In a multi-process test, an action's return tells you about the process you called, not about the ones it talks to; assert the local effect immediately and the remote effect only after an explicit wait. Review test hunks in a bug-fix PR as carefully as the fix, since a flaky test costs every later PR.

Classification

The survey's classification of this bug. The explorer charts these fields across all bugs; the method page explains them.

Field Value
Symptom assert
Worst effect observed test-failure-only
Seen in functional-test
Scope test-code
Trigger Normal use (ordinary-path)
Phase steady-state
Side n/a
Component test-harness
Root cause kind ordering
Fix kind test-only
Detection ci-intermittent
Needs a peer that is not libmultiprocess C++ no
Needed a sanitizer to see no
Confidence high