fix(test): stop test_download_policies hanging on a double-counted download - #20
Merged
Merged
Conversation
…wnload
This test has been timing out at its own 120s TIMEOUT on i686, Windows
and Ubuntu, blocking three PRs. It is not architecture-specific and never
was; it is a race that any sufficiently loaded machine loses.
The event loop breaks only on exact equality of counters that never
decrease:
if synced_a == EXPECTED_A_SYNCED
&& downloaded_a.len() == EXPECTED_A_DOWNLOADED
...
and `downloaded_*` was pushed from two event arms that are not mutually
exclusive:
- ContentReady { hash } -- emitted by `on_download_ready` when a
download completes (engine/live.rs);
- InsertRemote { content_status } -- where the status comes from
`content_status_cb(entry.content_hash())`, evaluated when the event
is CONVERTED (engine.rs), not when the entry synced.
Under scheduling pressure the download finishes and emits ContentReady
before its InsertRemote reaches the subscriber. By the time that event
converts, the content is present, so its status reads Complete and the
same key is recorded twice. downloaded_b.len() reaches 4 against an
expected 3, the equality can never hold again, and the loop spins until
the deadline.
Reproduced locally by saturating all 8 cores: 40 consecutive passes when
idle, then failures under load. Instrumenting every push site proved the
mechanism directly rather than by inference -- 2 of 14 loaded runs
printed "DUPE b via InsertRemote{Complete}" and exactly 2 timed out, the
counts matching. That also corrected the ordering: ContentReady arrives
first, and InsertRemote is the duplicate.
This is a test bug, not a product bug. The two events mean different
things -- "download finished" versus "entry synced, content already
present" -- and a real consumer must handle both. Only the test assumed
they were exclusive, so recording each key once is what it actually
wanted; the assertions already compare exact contents.
Also relax `==` to `>=`. The dedup fixes this instance, but an exact
comparison against a monotonic counter is a hang waiting to happen: any
future overshoot would spin for 120s with no diagnosis. With `>=` the
loop exits and the existing assertions report the discrepancy legibly.
Verified: 0 failures in 25 runs under full CPU load, against a pre-fix
baseline of 2 in 14 under the same load. Full krikos-docs suite green
(99 passed).
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
Documentation for this PR has been generated and is available at: https://holon-technologies.github.io/iroh/pr/20/docs/krikos/ Last updated: 2026-08-01T20:11:53Z |
jonaswre
added a commit
that referenced
this pull request
Aug 2, 2026
* fix(test): un-ignore four flaky tests; fix the content_status race
Four of the five tests carrying #[ignore = "flaky"] are now enabled.
Three of them were not flaky at all any more, and the fourth had a real
race with a measurable cause.
Measured first, before changing anything -- 5 runs of all five ignored
tests:
connect_via_relay_becomes_direct_and_sends_direct 5/5 pass
sync_restart_node 5/5 pass
sync_big 5/5 pass
sync_full_basic 4/5 FAIL
test_roundtrip_bytes_small 5/5 FAIL
The three that pass were left ignored long after whatever made them
flaky stopped happening. Nothing re-checks an #[ignore], so they simply
stayed off.
sync_full_basic passes in isolation and fails only alongside other
tests. The failure is not a timeout:
Event didn't match any matcher:
InsertRemote { ..., content_status: Incomplete }
Its matchers required `content_status: ContentStatus::Missing`. But
content_status is evaluated when the event is CONVERTED, not when the
entry synced -- the same timing-dependent field behind the double-count
fixed in #20 -- so whether a download has started by then is a race.
Measured which values actually occur, over 20 runs under full CPU load,
by accepting any status and logging it:
peer0/from-peer1 Missing 20/20
peer2/hash0 Incomplete 12, Missing 8
peer2/hash1 Missing 13, Incomplete 7
Complete never observed
So "not yet complete" is a real assertion that holds, while the
Missing/Incomplete split is pure timing. Match both. Applied to all six
sites, including sync_restart_node's three -- those pass today but carry
the identical latent race.
Verified: the four run together 12 times under full CPU saturation with
0 failures, in the configuration that previously failed sync_full_basic
4 times in 5. Full suites green with nothing skipped -- krikos-docs
102/102, krikos 155/155.
test_roundtrip_bytes_small stays ignored and needs a decision, not a
fix: it fails 5/5, so it is broken rather than flaky and has never given
signal. It asserts `expected.addr() == actual.addr()`, i.e. that
get_bytes hands back the same allocation add_bytes was given. That is an
implementation detail the store does not guarantee, which the ignore
reason itself concedes ("I need a reliable way to keep the handle
alive").
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
* fix(test): enable test_roundtrip_bytes_small by dropping an unfounded assertion
Last of the five #[ignore = "flaky"] tests. It was not flaky: it failed
5/5, so it had never given signal, and the "flaky" label hid that.
It asserted
assert_eq!(&expected.addr(), &actual.addr(), ...)
i.e. that `get_bytes` hands back the same allocation `add_bytes` was
given. The store makes no such promise:
- reads go through `export_bao(..).data_to_bytes()`;
- an entry may be `MemOrFile::Mem` or `MemOrFile::File`, and from disk
a copy is unavoidable;
- zero-copy is documented only as an internal property of the
in-memory variant (store/fs/bao_file.rs), not as API behaviour;
- it additionally requires a live handle, which the test had no
reliable way to hold -- the ignore reason said exactly this.
So the assertion was true only by coincidence. Drop it and keep what the
API does promise: the data round-trips, the hash matches, and the entry
reaches completion.
The alternative -- making zero-copy a public guarantee so the assertion
becomes honest -- was rejected deliberately. It would foreclose
encryption at rest, compression and checksum-on-read for the sake of one
assertion. Read-path allocation behaviour belongs in a benchmark, which
says "this should stay fast" without freezing how. The comment in the
test records that reasoning so the assertion is not reinstated blindly.
Nothing is lost by removing it: the test has been disabled and failing,
so it was protecting nothing.
Also refresh scripts/determinism-boundaries.txt. Removing one #[ignore]
line from krikos/src/endpoint/tests.rs shifted every boundary below it.
Verified this is pure line drift before refreshing: 1078 entries before
and after, 0 with any change to kind/file/code, exactly 22 line numbers
moved by -1 with identical code text.
No #[ignore = "flaky"] remains in the tree. check-flaky-sweep-scope.sh
now reports 0 flaky tests watched, which is the intended end state: a
red nightly sweep from here means a genuinely new flake.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
* fix(test): drop the import orphaned by removing the addr assertion
`SliceInfoExt` provides `.addr()`. Removing that assertion in the
previous commit left the import unused, which under CI's `-Dwarnings` is
a hard error -- it failed clippy, MSRV and every test job on every
platform.
My local check did not catch it because `cargo nextest run` does not
compile with warnings-as-errors: 115/115 passed while the code did not
build the way CI builds it. Running the tests answers a different
question from "does this compile cleanly", and I reported the first as
if it settled the second.
Verified this time by exit code rather than absence of output:
cargo check --workspace --all-targets --all-features (-Dwarnings) 0
cargo clippy --workspace --all-targets --all-features -D warnings 0
cargo fmt --all -- --check 0
plus krikos-blobs 115/115 and krikos-docs 102/102.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
---------
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
test_download_policieshas been timing out at its own 120sTIMEOUTon i686, Windows and Ubuntu, blocking #16, #17 and #19. It is not architecture-specific and never was — it is a race that any sufficiently loaded machine loses.The bug
The event loop breaks only on exact equality of counters that never decrease:
and
downloaded_*was pushed from two event arms that are not mutually exclusive:ContentReady { hash }on_download_readywhen a download completes (engine/live.rs:686)InsertRemote { content_status }content_status_cb(...), evaluated when the event is converted (engine.rs:348)Under scheduling pressure the download finishes and emits
ContentReadybefore itsInsertRemotereaches the subscriber. By the time that event converts, the content is present — so its status readsCompleteand the same key is recorded twice.downloaded_b.len()reaches 4 against an expected 3, the equality can never hold again, and the loop spins to the deadline. That is why the timing is always binary: ~0.2s or exactly 120s, never between.Evidence
Reproduced locally by saturating all 8 cores: 40 consecutive passes when idle, then failures under load.
Instrumenting every push site proved the mechanism directly rather than by inference:
The counts match exactly. This also corrected my initial reading of the ordering:
ContentReadyarrives first, andInsertRemoteis the duplicate.Why this is a test bug, not a product bug
The two events mean different things — "download finished" versus "entry synced, content already present" — and a real consumer must handle both. Only the test assumed they were exclusive. Recording each key once is what it actually wanted; the assertions already compare exact contents.
The change
==→>=. The dedup fixes this instance, but an exact comparison against a monotonic counter is a hang waiting to happen — any future overshoot would spin for 120s with no diagnosis. With>=the loop exits and the existing assertions report the discrepancy legibly.Verification
krikos-docssuite green (99 passed)🤖 Generated with Claude Code