You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
a_peer_returns_after_minutes_and_hours_without_errors_or_a_helper fails under load (early eof, return slower than 5 s) #271
Record of a failure shape, not a classification (docs/known-flaky-tests.md: a test enters that list only after diagnosis).
CI occurrence. macOS job, release PR 270 (version numbers only; the same test passed on PR 269's macOS job a few hours earlier), 2026-10-12 10:25Z: after the 300 s outage phase printed real return tunnel=275.792166ms the next phase failed with Error: early eof. The test body is daemon.rs, the step that connects to the dial listener after the peer restarts and calls read_exact once.
Local. 25 sequential runs of the same test binary: 25 pass. 60 runs as 12 parallel processes in 5 rounds on an otherwise idle Mac: 6 fail, all on assert!(returned.elapsed() < Duration::from_secs(5)) (daemon.rs:10132), i.e. restarting the peer and getting a first reply took longer than 5 s when twelve debug binaries compete for the machine. None of the six was early eof, so the CI failure shape is not reproduced yet.
Hypothesis (unproven). After the peer restarts, presence.offline(peer) clears and the test makes ONE request. docs/failure-modes.md says an application must retry a new request that closed while the peer was offline; a request made in the window before the tunnel has attached can be closed (EOF) rather than held. If so the test needs to retry on EOF within its 3 s budget, which matches the documented behaviour. The 5 s bound measures FabricNode::start as well as the return and is load-sensitive on its own.
Not a product regression as far as I can tell: the failing code path did not change between the passing and failing runs.
2026-10-13: a second CI occurrence, on README-only PRs 288 and 289 (macOS, outage=300s phase passed with real return tunnel=280ms, then the second round failed with 'early eof'), and passes on 285 with the same base, so it is intermittent. It happens on main code that predates the 0.2.40 pipe-thread change (first record 2026-10-12, 0.2.39). Local: 40 runs as 8 parallel processes x 5 rounds on macOS at 0f main: 39 pass, 1 fails on the 5 s return bound (daemon.rs:10228); no 'early eof' reproduced. Still unclassified; it stays out of docs/known-flaky-tests.md until diagnosed. Next step: have the test retry once on EOF inside its 3 s budget only if a failing run shows the request landed before the tunnel attached.
Read-only investigation on e5126b9, Linux, 2026-10-15. No source changes and no production-peer traffic.
The requested runs did not reproduce either failure shape:
Run mode
Attempts
Passed
Early EOF
5 s bound failures
Other failures
Serial, one test process
50
50
0
0
0
Moderate parallel load, four test processes
50
50
0
0
0
These were separate exact-test Cargo invocations with backtraces enabled, through the normal build-admission wrapper. Recorded test-start/test-end intervals confirm four actual overlapping tests in the second phase. Each invocation exercised both virtual outages. The serial phase ran on a shared machine, not an otherwise idle machine; observed one-minute host load was 8.93–28.28, versus 7.79–8.52 during the parallel phase. An isolated mount namespace supplied the test's /bin/cat fixture; no global filesystem change. Source revision and daemon source hash were identical before and after.
Real return times (minimum / median / maximum):
Mode
300 s virtual outage
14,400 s virtual outage
Serial
393 / 425 / 604 ms
393 / 422 / 678 ms
Four concurrent
385 / 398 / 420 ms
386 / 402 / 439 ms
What the existing CI output establishes: on PR 317 Linux, the first return printed 360 ms before early eof; on PR 319 macOS it printed 277 ms before early eof. That does not identify the failing read. The test performs a fresh x readiness request at the start of each iteration, as well as a y request after each restart. Either read in the second iteration could produce the observed output. The 5 s assertion also includes FabricNode::start, whereas the inner presence/read block has its own 3 s limit.
Production versus virtual time: an initial tunnel attach failure can close a local client in production too. The attach loop fails the local session when it has never attached; only an established session gets the reconnect behavior. Peer presence and mux admission do not prove that this exact session has completed its tunnel Hello. In particular, canonical mux replacement closes the previous connection when a preferred duplicate is selected. A replacement after mux admission but before the tunnel Hello exchange is therefore a candidate for a fresh request closing. This path does not require virtual time. No failing trace links that interleaving to this issue yet. It is not an established diagnosis of the CI failure.
The test also has a real simulation limitation: it advances Tokio time around real endpoints and real I/O. In the locked dependencies, Iroh 1.0.2 delegates QUIC timers to Noq's Tokio timers but inherits Noq 1.3.0's default real-time now(). Advancing Tokio time does not advance that protocol clock or Fabric's std::time::Instant clocks. Resuming Tokio time retains the advanced offset. This makes virtual-clock interactions worth investigating, but does not prove they caused the EOF or that production is unaffected.
Conclusion and smallest next change: the EOF remains unclassified; 0/100 here is not evidence that it is only a slow test. I do not recommend a retry, a relaxed deadline, or a flaky-test classification yet. The smallest test-only change is error context on both reads and the restart/wait phases, including the outage duration and whether the request was initial-readiness or post-return. Keep the existing timing bounds. A resulting failure can then distinguish the phase before adding targeted connection/attach tracing. No such source change was made in this investigation.
The full 100 attempt records, raw logs, timing summaries, source hashes and harness have been retained with the investigation evidence.
Follow-up: the unconfirmed mux-replacement candidate is now tracked separately in #321. The diagnostics-only PR is #322: outage duration and phase context at the existing test's reads, connects/writes, stop/restart, and presence/return waits. It preserves the existing retries, timing bounds, clock operations, and production code.
The focused test passed both outage phases in 8.06 s. A controlled missing-/bin/cat fixture run verified that the failure now identifies outage=300s: initial readiness read, retaining early eof as the underlying cause. That controlled fixture failure is not a reproduction of the CI race.
The phase diagnostics added in #322 identified the Linux failure on PR #328 at exact head 2754dca1d4703e7eb045d5bfc9912d85c9d5a3ef:
outage=300s virtual; real return tunnel=360.273494ms
Error: outage=14400s: initial readiness read
Caused by:
early eof
Exact-head Linux job: 496 passed, 1 failed, 2 ignored. The five-minute return completed, then the next fresh stream failed its readiness read before the peer was stopped or time advanced for the four-hour case. This failure is therefore outside that case's post-return read and five-second return bound.
This identifies the test phase, not the cause or whether the stream had completed its tunnel attach. There is no trace here proving the preferred-duplicate candidate in #321, nor evidence that an already-running session lost data. No rerun, retry, timing change, or daemon change was made as part of this log inspection.
Observed again on PR #337 at a926de6, macOS run https://github.com/compoundingtech/fabric/actions/runs/39236211026/job/118005777467: a_peer_returns_after_minutes_and_hours_without_errors_or_a_helper failed with outage=14400s: initial readiness read / early eof (300s return succeeded). 558 other library tests passed, including pairing tests. Linux deterministic and Nix build are green. No outage-test, default transport or suppression changes; recording this distinct initial-readiness occurrence and rerunning only the failed hosted job unchanged.
Sighting: the macOS job failed this test again on #341 at cb4e01d (run 40918578927, 2026-10-29), unrelated to that diff (a restack). It also failed once on #340's first run and passed on rerun. Pattern is unchanged: macOS only, under load. Still no repro on Linux; next step when work resumes is to capture the read that returns early EOF.
Activity
myobie commentedon Oct 13, 2026
2026-10-13: a second CI occurrence, on README-only PRs 288 and 289 (macOS, outage=300s phase passed with real return tunnel=280ms, then the second round failed with 'early eof'), and passes on 285 with the same base, so it is intermittent. It happens on main code that predates the 0.2.40 pipe-thread change (first record 2026-10-12, 0.2.39). Local: 40 runs as 8 parallel processes x 5 rounds on macOS at 0f main: 39 pass, 1 fails on the 5 s return bound (daemon.rs:10228); no 'early eof' reproduced. Still unclassified; it stays out of docs/known-flaky-tests.md until diagnosed. Next step: have the test retry once on EOF inside its 3 s budget only if a failing run shows the request landed before the tunnel attached.
myobie commentedon Oct 15, 2026
Read-only investigation on e5126b9, Linux, 2026-10-15. No source changes and no production-peer traffic.
The requested runs did not reproduce either failure shape:
These were separate exact-test Cargo invocations with backtraces enabled, through the normal build-admission wrapper. Recorded test-start/test-end intervals confirm four actual overlapping tests in the second phase. Each invocation exercised both virtual outages. The serial phase ran on a shared machine, not an otherwise idle machine; observed one-minute host load was 8.93–28.28, versus 7.79–8.52 during the parallel phase. An isolated mount namespace supplied the test's
/bin/catfixture; no global filesystem change. Source revision and daemon source hash were identical before and after.Real return times (minimum / median / maximum):
What the existing CI output establishes: on PR 317 Linux, the first return printed 360 ms before
early eof; on PR 319 macOS it printed 277 ms beforeearly eof. That does not identify the failing read. The test performs a freshxreadiness request at the start of each iteration, as well as ayrequest after each restart. Either read in the second iteration could produce the observed output. The 5 s assertion also includesFabricNode::start, whereas the inner presence/read block has its own 3 s limit.Production versus virtual time: an initial tunnel attach failure can close a local client in production too. The attach loop fails the local session when it has never attached; only an established session gets the reconnect behavior. Peer presence and mux admission do not prove that this exact session has completed its tunnel Hello. In particular, canonical mux replacement closes the previous connection when a preferred duplicate is selected. A replacement after mux admission but before the tunnel Hello exchange is therefore a candidate for a fresh request closing. This path does not require virtual time. No failing trace links that interleaving to this issue yet. It is not an established diagnosis of the CI failure.
The test also has a real simulation limitation: it advances Tokio time around real endpoints and real I/O. In the locked dependencies, Iroh 1.0.2 delegates QUIC timers to Noq's Tokio timers but inherits Noq 1.3.0's default real-time
now(). Advancing Tokio time does not advance that protocol clock or Fabric'sstd::time::Instantclocks. Resuming Tokio time retains the advanced offset. This makes virtual-clock interactions worth investigating, but does not prove they caused the EOF or that production is unaffected.Conclusion and smallest next change: the EOF remains unclassified; 0/100 here is not evidence that it is only a slow test. I do not recommend a retry, a relaxed deadline, or a flaky-test classification yet. The smallest test-only change is error context on both reads and the restart/wait phases, including the outage duration and whether the request was initial-readiness or post-return. Keep the existing timing bounds. A resulting failure can then distinguish the phase before adding targeted connection/attach tracing. No such source change was made in this investigation.
The full 100 attempt records, raw logs, timing summaries, source hashes and harness have been retained with the investigation evidence.
myobie commentedon Oct 16, 2026
Follow-up: the unconfirmed mux-replacement candidate is now tracked separately in #321. The diagnostics-only PR is #322: outage duration and phase context at the existing test's reads, connects/writes, stop/restart, and presence/return waits. It preserves the existing retries, timing bounds, clock operations, and production code.
The focused test passed both outage phases in 8.06 s. A controlled missing-
/bin/catfixture run verified that the failure now identifiesoutage=300s: initial readiness read, retainingearly eofas the underlying cause. That controlled fixture failure is not a reproduction of the CI race.myobie commentedon Oct 16, 2026
The phase diagnostics added in #322 identified the Linux failure on PR #328 at exact head
2754dca1d4703e7eb045d5bfc9912d85c9d5a3ef:Exact-head Linux job: 496 passed, 1 failed, 2 ignored. The five-minute return completed, then the next fresh stream failed its readiness read before the peer was stopped or time advanced for the four-hour case. This failure is therefore outside that case's post-return read and five-second return bound.
This identifies the test phase, not the cause or whether the stream had completed its tunnel attach. There is no trace here proving the preferred-duplicate candidate in #321, nor evidence that an already-running session lost data. No rerun, retry, timing change, or daemon change was made as part of this log inspection.
schickling-assistant commentedon Oct 19, 2026
Observed again in PR #332 at head 27c3823. Linux deterministic run attempt 1:
a_peer_returns_after_minutes_and_hours_without_errors_or_a_helperfailed withoutage=14400s: post-return read, caused byearly eof; preceding 300s virtual outage returned in 430.554801ms. Library result: 511 passed, 1 failed, 2 ignored. Failed job: https://github.com/compoundingtech/fabric/actions/runs/39221160652/job/117956525939 . The failed job was rerun at the unchanged head, and the entire deterministic workflow passed (16m37s): https://github.com/compoundingtech/fabric/actions/runs/39221160652/job/117964313454 . No transport change or test suppression was made between attempts; cause remains unproven.Posted on behalf of @schickling
agent_identitysessionagent_personaagent_supervisoragent_toolagent_tool_versionagent_runtimeagent_modelworktreeschickling-assistant commentedon Oct 19, 2026
Observed again on PR #337 at a926de6, macOS run https://github.com/compoundingtech/fabric/actions/runs/39236211026/job/118005777467: a_peer_returns_after_minutes_and_hours_without_errors_or_a_helper failed with outage=14400s: initial readiness read / early eof (300s return succeeded). 558 other library tests passed, including pairing tests. Linux deterministic and Nix build are green. No outage-test, default transport or suppression changes; recording this distinct initial-readiness occurrence and rerunning only the failed hosted job unchanged.
Posted on behalf of @schickling
agent_identitysessionagent_personaagent_supervisoragent_toolagent_tool_versionagent_runtimeagent_modelworktreemyobie commentedon Oct 29, 2026
Sighting: the macOS job failed this test again on #341 at cb4e01d (run 40918578927, 2026-10-29), unrelated to that diff (a restack). It also failed once on #340's first run and passed on rerun. Pattern is unchanged: macOS only, under load. Still no repro on Linux; next step when work resumes is to capture the read that returns early EOF.