Describe the bug
governance_history.test_ledger_is_readable waits for a forced ledger chunk on the primary only, then immediately reads the ledger from every backup with a 5s budget and no synchronisation. When a backup has not yet received and flushed the forced chunk, it answers 404 until the budget expires.
tests/governance_history.py:
def test_ledger_is_readable(network, args):
primary, backups = network.find_nodes()
target_seqno = network.create_and_wait_for_ledger_chunk(primary)
for node in (primary, *backups):
with node.get_ledger_from_api(target_seqno, local_only=True) as ledger:
tests/infra/network.py::create_and_wait_for_ledger_chunk only ever waits on the node it was given:
node.wait_for_ledger_chunk(target_seqno, timeout=timeout) # primary only
and tests/infra/node.py::get_ledger_from_api defaults to timeout=5, polling every 0.1s. Nothing waits for the backups to catch up, so the 5s poll is the only synchronisation.
To Reproduce
Intermittent. It surfaces in the slower/perturbed CI configurations, where a backup can lag the primary by more than 5s:
ASAN (instrumentation slowdown)
Long Shuffled/LTS/Snmalloc (randomised scheduling)
Failure signature:
[N] GET /node/ledger_chunk?since=371
404 {"error":{"code":"ResourceNotFound","message":"This node has no ledger chunk including index 371"}}
... ~50 identical 404s over 5s ...
TimeoutError: Could not download ledger through seqno 553 from node 18 after 5s
One observed instance reported no ledger chunk including index 1, i.e. a node that had written essentially nothing yet - which is timing, not chunk-accounting drift.
Expected behavior
The test should wait for each node it is about to read from to have the chunk, rather than inferring it from the primary.
Additional context
Two candidate fixes:
- In
test_ledger_is_readable, call node.wait_for_ledger_chunk(target_seqno) for each node before get_ledger_from_api, so each is synchronised individually.
- Have
create_and_wait_for_ledger_chunk optionally wait on all nodes in the network rather than just one.
(1) is the smaller change and keeps the waiting where the reading happens.
Raising the timeout alone would only make the window wider, not remove the race.
Note that create_and_wait_for_ledger_chunk already carries a comment about tolerating reserved-signature ordering, so this area has needed timing accommodations before:
# A signature whose seqno was reserved before this request may consume
# the snapshot flag after the request commits. In that case the chunk
# ends immediately before the request; otherwise it ends at a later
# signature. The preceding seqno is covered in either ordering.
Found while investigating CI failures on #8242, #8243 and #8246. It presents as the same test failing in different jobs on different PRs while passing in those same jobs on sibling PRs containing identical code - and it reproduces on #8242, which makes no changes to the chunker at all, so it is not caused by those PRs.
Describe the bug
governance_history.test_ledger_is_readablewaits for a forced ledger chunk on the primary only, then immediately reads the ledger from every backup with a 5s budget and no synchronisation. When a backup has not yet received and flushed the forced chunk, it answers 404 until the budget expires.tests/governance_history.py:tests/infra/network.py::create_and_wait_for_ledger_chunkonly ever waits on the node it was given:and
tests/infra/node.py::get_ledger_from_apidefaults totimeout=5, polling every 0.1s. Nothing waits for the backups to catch up, so the 5s poll is the only synchronisation.To Reproduce
Intermittent. It surfaces in the slower/perturbed CI configurations, where a backup can lag the primary by more than 5s:
ASAN(instrumentation slowdown)Long Shuffled/LTS/Snmalloc(randomised scheduling)Failure signature:
One observed instance reported
no ledger chunk including index 1, i.e. a node that had written essentially nothing yet - which is timing, not chunk-accounting drift.Expected behavior
The test should wait for each node it is about to read from to have the chunk, rather than inferring it from the primary.
Additional context
Two candidate fixes:
test_ledger_is_readable, callnode.wait_for_ledger_chunk(target_seqno)for each node beforeget_ledger_from_api, so each is synchronised individually.create_and_wait_for_ledger_chunkoptionally wait on all nodes in the network rather than just one.(1) is the smaller change and keeps the waiting where the reading happens.
Raising the timeout alone would only make the window wider, not remove the race.
Note that
create_and_wait_for_ledger_chunkalready carries a comment about tolerating reserved-signature ordering, so this area has needed timing accommodations before:Found while investigating CI failures on #8242, #8243 and #8246. It presents as the same test failing in different jobs on different PRs while passing in those same jobs on sibling PRs containing identical code - and it reproduces on #8242, which makes no changes to the chunker at all, so it is not caused by those PRs.