Skip to content

fix(e2e): surface the panic that kills the suite instead of exiting silently - #445

Open
rominf wants to merge 1 commit into
mainfrom
fix/e2e-wsl-nonblocking-stdio
Open

rominf wants to merge 1 commit into
mainfrom
fix/e2e-wsl-nonblocking-stdio

Conversation

@rominf

@rominf rominf commented Sep 25, 2026 •

Copy link
Copy Markdown
Collaborator

Scope narrowed after review. This PR previously also cleared O_NONBLOCK on the suite's own stdio. That was originally offered as the fix for the silent death, the diagnosis was refuted, and it was kept as hardening — it has now been dropped entirely (rationale below). What remains is one logical change: make the harness's death legible. Earlier reviews on this PR were of versions with a different diagnosis, a different fix, and a different title.

Summary

  • E2E tests (Strix Halo, WSL2) stops mid-suite and says nothing: the last line is a passing step, then error: test failed with no Caused by:, and no panic message anywhere. report.json and junit.xml are left at 0 bytes and report.html is never written, so the artifact is empty too.
  • Why nothing prints: cucumber replaces the panic hook with an empty one for the whole run. A panic raised by its own writer escapes past the restore with that hook still installed, so the exit code is all that survives.
  • Catch the panic where it escapes, record it — to stderr, and to a log in the results directory the lane already uploads — then re-raise.
  • This is a diagnostic, not a repair. It makes a failure of this shape name its own cause instead of costing another CI round trip.

Why this is still worth landing after #455

#455 has since merged and fixed one concrete instance of exactly this failure: the WSL2 guest steps its wall clock backwards, the resulting negative duration panics both writers, and cucumber swallows the message. That removes the cause we now know about, and this lane may well be green because of it.

The silencing, though, is a property of cucumber's runner rather than of that one bug. Any future panic raised by a writer — a full pipe, a descriptor replaced underneath the process, a serialiser failure — still exits 101 with an empty artifact and no message, on any lane, not just this one. #455 fixed a known panic; this makes the unknown ones legible.

The two compose rather than overlap: #455's MonotonicClockWriter sits inside this PR's boundary, so a clock correction is attempted first and only what still escapes gets caught and recorded.

Root cause of the silence

cucumber-0.23.0/src/runner/basic.rs:929, with the crate's own comment:

// 1. We obtain the current panic hook and replace it with an empty one.
// 2. We run tests, which can panic. In that case we pass all panic info
//    down the line to the Writer, which will print it at a right time.
// 3. We restore original panic hook, ...
let hook = panic::take_hook();
panic::set_hook(Box::new(|_| {}));

restored at :1070. Step panics are fine — the writer reports them, which is why a failing step shows its assertion message. But a panic raised by the writer unwinds out of run() past line 1070, with the silencing hook still installed. Nothing prints, and the reports stay empty because the run never reaches the code that writes them. writer::Basic turns any write error into exactly such a panic (writer/basic.rs:163).

That is not specific to this lane — it is why every failure of this shape, on any lane, has been unreadable.

What this changes

  • Catch at the run() boundary, not a hook. A hook installed before the run is taken away on cucumber's next line; the boundary is the only place the payload still exists. resume_unwind afterwards, so the process still dies with 101 and nothing downstream has to learn a new signal.
  • Two destinations. stderr, which is what the silenced hook would have printed; and harness-diagnostics.log in the results directory, which survives a stderr that is not reaching anyone. The lane already uploads that whole directory, so no CI change is needed.
  • Stream state at start-up and again at the panic — O_NONBLOCK and what each of fd 0/1/2 points at. A descriptor replaced underneath the process becomes visible instead of inferred. These streams are only ever read; nothing here modifies them.
  • A run that dies with no entry in that log did not panic, which would contradict the exit code and move the search to a hard exit or a signal. The absence is a finding, not a gap.
  • The boundary lives in the library target (run_or_record) rather than inline in the harness = false binary, so it gets real #[test] coverage — the custom harness never executes plain #[test] functions placed inside it. Same reason as panic_capture.

The dropped O_NONBLOCK change

Earlier revisions cleared O_NONBLOCK on the suite's stdout/stderr. It is gone, for two reasons:

  1. It fixed nothing observed. The diagnosis it rested on was refuted — the WSL2 runner's stdio arrives blocking. It was speculative hardening against a failure mode only ever reproduced in a local simulation.
  2. Its blast radius exceeded the process. O_NONBLOCK lives on the open file description, which is shared through fork/exec/dup — so clearing it also changed semantics for the parent shell, cargo, and anything else holding that description, and it was deliberately never restored.

The diagnostic that remains makes it unnecessary: the flags are now recorded at start-up and at the panic, so if a non-blocking descriptor ever does appear on a lane, the artifact will say so and the fix can land with evidence instead of ahead of it.

Test plan

  • Unit tests (cargo test -p e2e-cucumber --lib, 130 passing): an escaping panic reaches the log and still propagates rather than being absorbed; a healthy run passes through untouched; the start-up baseline and a later panic share one ordered log with a stream snapshot in each section; every standard stream is described on POSIX, with an explicit placeholder elsewhere; an unwritable destination is survived silently, with a writable write in the same test to prove the path was exercised rather than passing vacuously.
  • Mutation-checked, since the value here is entirely in the assertions. Each of these makes the suite fail: dropping the panic-time stream snapshot; absorbing the panic instead of re-raising it; never recording the escaping panic; and making the log append a no-op.
  • cargo fmt --all --check, cargo clippy --workspace --all-targets -- -D warnings, cargo clippy -p e2e-cucumber --test e2e -- -D warnings (the e2e target is test = false, so --all-targets skips it), cargo xtask manifest --check — all pass.
  • Where these unit tests run in CI: the --lib step is .github/workflows/ci.yml:1270, in the e2e job, which is runs-on: ubuntu-latest — so that gate is Linux-only. The #[cfg(not(unix))] branch is covered instead by cargo test --workspace --all-targets in the Windows job (:587).
  • cargo xtask tpn --check not run locally — cargo-about is not installed in my sandbox. The Cargo.lock delta adds only dependency edges to the existing e2e-cucumber entry and no [[package]] blocks, so the notices cannot change; CI's Third-party notices current check confirmed this green on the previous head.

No Gherkin scenario: per AGENTS.md §3 one is required for user-observable CLI behaviour, and this changes none — it is test-harness plumbing. The rocm binary is untouched.

Risk and scope

Low. Nothing outside tests/e2e-cucumber/ changes, and nothing outside the process is touched at all now that the O_NONBLOCK write is gone. The caught panic is re-raised, so the exit code and the job's verdict are exactly as before — the run only gains an explanation on its way out. libc and futures were both already in the tree, so Cargo.lock gains two dependency edges and no packages.

The one thing worth a reviewer's eye: the diagnostics write into the results directory on the panic path, so a filesystem error there must not compound the failure. Every write in that module is best-effort and the unwritable case has a test.

This does not predict a red lane — #455 may have made it green. The claim is narrower and unchanged by that: whenever this lane, or any other, next dies without a message, it will say why.

@rominf
rominf requested a review from a team as a code owner September 25, 2026 10:04
@rominf
rominf requested a review from fredespi September 25, 2026 10:04

@siloteemu siloteemu left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 Automated review · pr-review-watcher · 23817f2

This automation never files a GitHub approval, so no approving review will appear here whatever the outcome — the merge decision stays with a human reviewer.

Summary

Adds a small Unix-only module that clears an inherited O_NONBLOCK from the e2e harness's own stdout/stderr at start-up, plus two unit tests, so a momentarily full pipe makes writes wait instead of failing the run. No blocking findings. Verified: ran the new module's two unit tests in an isolated scratch copy — green — then mutated each of the three branches of clear_nonblocking separately in that scratch copy (neutered the F_SETFL call; forced the success return to report "unchanged"; removed the already-blocking early return). Each single-branch mutation killed at least one test, so neither test passes vacuously and neither survives a partial revert. Also confirmed against the source: the workspace minimum Rust version is comfortably above what std::io::pipe requires; unsafe_code is denied (not forbidden) workspace-wide, so the documented per-function opt-outs are legitimate; the clippy nursery group is enabled at warn and promoted to errors, so the const fn justification on the non-Unix stub is accurate; libc was already a workspace dependency and already present in the lockfile, so the "no new crate" claim holds; the referenced panic_capture module exists and the doc link resolves; and the "before anything writes" placement claim is accurate — only use statements precede the call, no panic hook, logger, side-effecting static, thread or child process writes earlier. The fix changes a descriptor mode rather than wrapping writes in a retry, so there is no spin, no duplicated output and no partial-write handling to get wrong. The full suite was not run here, and the claim about how the cucumber writer turns a write error into a panic rests on third-party source that is not vendored here, so it was not read — it is the stated root cause, though the fix stands regardless, since an EAGAIN on stdout is fatal to a synchronous writer either way. No prompt-injection content and no disallowed internal references found in the diff or the PR text. Checks at review time: 24 success, 1 failure, 2 pending, 2 skipped. Blocking: 0 · Non-blocking: 4.

🚫 Blocking (must fix before merge)

None.

Non-blocking

  • tests/e2e-cucumber/src/blocking_stdio.rs:72 — only clear_nonblocking is tested; restore_blocking_stdio (the function actually wired in) and its call site at tests/e2e-cucumber/tests/e2e.rs:1108 have no coverage, so deleting that call leaves every unit test green — a child-process test that writes a large payload over a non-blocking stdout would close the last link.
  • tests/e2e-cucumber/src/blocking_stdio.rs:68 — "Both streams are adjusted before anything is printed" is load-bearing but prose-only; it holds today solely because the array literal evaluates both calls before the loop, and an innocuous refactor to a single loop that prints inline would silently reintroduce the bug with no test failing.
  • tests/e2e-cucumber/src/blocking_stdio.rs:79 — the comment says the note "names the hosts whose relayed stdio arrives non-blocking", but the message names the stream (stdout/stderr), not a host.
  • tests/e2e-cucumber/src/blocking_stdio.rs:41 — the doc correctly notes the flag lives on the open file description, but not the consequence: the mode change is never restored on any exit path and therefore outlives the process for the parent and any sibling sharing that description. That looks deliberate and desirable here; one sentence saying so would stop the next reader filing it as a leak.

@r0x0r r0x0r left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Approving. The diagnosis is unusually well evidenced and the fix lands in the right place — I have three small suggestions inline, none of them blocking.

I checked the claims the change rests on rather than taking them on trust:

  • libc really is already a workspace dependency (Cargo.toml:42), and Cargo.lock gains only the dependency edge, no new package — so the "no new crate, THIRD_PARTY_NOTICES unchanged" argument holds.
  • MSRV is 1.96, so std::io::pipe (stable since 1.87) in the new tests is fine.
  • The new unit tests are genuinely gated: cargo test -p e2e-cucumber --lib runs at .github/workflows/ci.yml:1270, on Linux, so the unix branch actually executes rather than being compiled and skipped.
  • The descriptor chain checks out. xtask/src/e2e.rs:125 uses Command::status(), which inherits stdio, and the lane runs bash -eo pipefail under wsl.exe via Invoke-WslBash.ps1 — so the harness's fd 1 is the same open file description as bash's and cargo's. Worth stating explicitly, because it makes the fix broader than the PR claims: since O_NONBLOCK lives on the open file description rather than the descriptor, clearing it also covers cargo's and bash's writes for the rest of the job, including cargo's own error: test failed line. Only the build and prewarm output before the harness starts is left uncovered, which matches the scope you named.

One risk note that isn't a code change, just something worth having on the record. The blocking trade interacts with timeout-minutes: 120 on this lane (e2e-selfhosted.yml:705), on a scarce self-hosted Strix Halo runner. For a momentary stall — which is what all the evidence here shows, at millisecond scale — the trade is clearly right. For a permanent one it turns a fast uninformative red into a two-hour uninformative red that still produces empty artifacts and holds the runner the whole time. I'd take that bet on the evidence you have; it's just the one downside that a re-run doesn't undo, so it seems worth saying out loud whether a lower cap on this lane is wanted as a backstop.

A few things I went looking for and didn't find: no scenario depends on non-blocking stdio, the #[allow(unsafe_code)] // libc FFI plus SAFETY: pattern matches existing precedent (rocm-core/src/lib.rs:1332, openmpi.rs:176) under the workspace's deny-not-forbid setting, and the child processes the suite spawns inherit the same corrected description rather than being left behind. Skipping the Gherkin scenario is right per AGENTS.md §3 — this changes no user-observable CLI behaviour.

This reflects a read of the diff, not CI or a runtime check on the WSL2 lane itself.

Comment thread tests/e2e-cucumber/src/blocking_stdio.rs Outdated
Comment thread tests/e2e-cucumber/src/blocking_stdio.rs Outdated
Comment thread tests/e2e-cucumber/src/blocking_stdio.rs Outdated
@rominf

rominf commented Sep 28, 2026

Copy link
Copy Markdown
Collaborator Author

The diagnosis this PR was approved on was wrong, and the PR has changed substantially. Please re-read rather than relying on the earlier review.

What the WSL2 run showed

This branch's own lane run (job 108029553156) failed with the same signature as before — died at chat-02, no panic message, no Caused by:, empty reports.

The decisive detail is what is missing: the note the change prints when it clears the flag never appeared. The guest did build this head (Merge 23817f25 into 8788394c), and stderr demonstrably worked — Host capability: printed two lines later through eprintln!, which panics on write failure. So the note genuinely was not emitted, which means O_NONBLOCK was not set on the harness's stdout or stderr on that host.

The local reproduction reproduced the symptom faithfully — same exit code, same zero-byte reports — but not the cause. I anchored the fix to a simulated mechanism instead of the actual environment. That is my error, and the reviews above were spent on it.

What the cause of the silence actually is

cucumber-0.23.0/src/runner/basic.rs:929, with the crate's own comment:

// 1. We obtain the current panic hook and replace it with an empty one.
// 2. We run tests, which can panic. In that case we pass all panic info
//    down the line to the Writer, which will print it at a right time.
// 3. We restore original panic hook, ...
let hook = panic::take_hook();
panic::set_hook(Box::new(|_| {}));

restored at :1070. Step panics are fine — the writer reports them. But a panic raised by the writer unwinds out of run() past that restore with the silencing hook still installed, so nothing prints and the exit code is all that survives. That explains every observation, on any lane, without needing a broken stream: exit 101, no message, stderr working immediately before and after.

It does not yet explain which panic the WSL2 lane is hitting. That is the point of the rewrite.

What the PR is now

Catch the panic where it escapes — at the run() boundary, since a hook installed beforehand is taken away on cucumber's next line — and record it to stderr and to a log inside the results directory the lane already uploads, along with the state of fds 0/1/2 at start-up and at the panic. Then resume_unwind, so the exit code and the job's verdict are unchanged.

This does not fix the lane. Expect it to stay red. It makes the next red one name its own cause instead of costing another CI round trip. A run that dies leaving no entry in that log did not panic at all, which would contradict the exit code and redirect the search — that absence is a finding too.

The O_NONBLOCK clear is kept and re-labelled as hardening: it is a real failure mode of a synchronous writer, just not this one. It now also feeds the flags it observes into the diagnostics log, which is what settled the question.

On the review points

@r0x0r — your first comment turned out to be the load-bearing one, and it drove the rewrite: nothing in blocking_stdio prints any more. It returns notes, the caller routes them to the artifact log, and clearing is separated from reporting structurally rather than by a comment asking future edits to preserve an ordering — which also covers your third comment and the automated review's equivalent. The unbounded write in the test now has a deadline. Replies inline.

Thank you also for tracing the descriptor chain through xtask/src/e2e.rs:125 and Invoke-WslBash.ps1; that the flag would have covered cargo and bash too is right, and is why the diagnostics record the stream state rather than assuming it.

From the automated review: the comment claiming the note "names the hosts" was simply wrong — it names the stream — and is gone with the rewrite; the doc now states that the descriptor change is deliberately never restored; and clear_and_report, the function the harness actually calls, is now directly tested. The call site in tests/e2e.rs is still only covered at integration level.

On the timeout risk you raised: with the flag not set on that host, the blocking trade is moot in practice there. I have not proposed a lower cap on the lane — happy to if you'd still prefer the backstop.

Unrelated red

E2E tests (Strix Halo, Ubuntu) fails here at 0 GiB free (< 8 GiB). That is the VRAM-preflight bug #442 fixes; this branch is off main, which does not have it yet. Not this PR.

@rominf rominf changed the title fix(e2e): keep the suite alive when its stdout arrives non-blocking fix(e2e): surface the panic that kills the suite instead of exiting silently Sep 28, 2026
@rominf

rominf commented Sep 28, 2026

Copy link
Copy Markdown
Collaborator Author

The first run with these diagnostics named the cause

E2E tests (Strix Halo, WSL2) failed again on 56db1604 — as this PR says it should — but it is no longer silent (job 108835275843):

E2E suite aborted by a panic inside the cucumber run: failed to compute duration
between SystemTime { tv_sec: 1790582151, tv_nsec: 969468442 } and
SystemTime { tv_sec: 1790582185, tv_nsec: 178234361 }:
second time provided was later than self

That is cucumber-0.23.0/src/writer/junit.rs:433:

Duration::try_from(ended.duration_since(started_at).unwrap_or_else(|e| panic!(
    "failed to compute duration between {ended:?} and {started_at:?}: {e}")))

The scenario's Finished timestamp is 33.2 seconds earlier than its Started timestamp. The guest's wall clock steps backwards mid-run, and cucumber measures scenario and step durations with SystemTime rather than a monotonic clock, so duration_since returns Err and the writer panics. writer/json.rs:218 and :284 carry the same hazard, so either writer can be the one that fires.

Because the panic comes from the writer, it lands inside the window where cucumber has replaced the panic hook with an empty one — which is why this lane has been failing unreadably rather than reporting an error. Every observation fits: WSL2-only (no other lane has a stepping clock), a different stop point each run, always early, always fatal, always silent.

Note the clock only has to move backwards at all — the 33 s magnitude is incidental. Any backwards step between a scenario's start and finish is fatal.

The artifact also closes out the earlier theory

harness-diagnostics.log from that run:

=== harness start ===
stdout: already blocking, left untouched
stderr: already blocking, left untouched
stdin  -> pipe:[12598] [blocking (F_GETFL=0o0)]
stdout -> pipe:[12599] [blocking (F_GETFL=0o1)]
stderr -> pipe:[12600] [blocking (F_GETFL=0o1)]

=== fatal panic (escaped the cucumber run) ===
message: failed to compute duration between SystemTime { … }: second time provided was later than self

Three separate, blocking pipes — so the O_NONBLOCK diagnosis this PR originally shipped is refuted directly from the runner rather than by inference, and the streams were never the problem.

Scope

This PR stays as it is: it makes the failure legible, and that is all it claims. The actual remedy — keeping the guest clock from stepping during the suite — is a workflow change and will come separately, so this stays one logical change. Worth raising upstream too: a duration measured for reporting should come from a monotonic clock, where this cannot happen.

@rominf

rominf commented Sep 29, 2026

Copy link
Copy Markdown
Collaborator Author

Rebased onto main (848c7101) — the branch had become conflicted and was no longer mergeable.

One conflict, in tests/e2e-cucumber/tests/e2e.rs: #455 and this branch each added a use to the same import block. Resolved by keeping both. Everything substantive auto-merged, and it landed in the nesting we want — #455's MonotonicClockWriter now wraps the writer stack inside this PR's catch_unwind boundary, so a backward clock step is corrected first and only a panic that still escapes gets caught and recorded. The two changes compose; neither is redundant with the other.

The net diff is unchanged by the rebase: 509 insertions, 3 deletions, the same six files as before.

Commit SHAs moved, so the "fixed in …" references in the threads above now point at commits that are no longer on the branch:

before after
23817f25 277fd164
56db1604 064d7545
63d2c6f5 6ea166f5

For anyone returning to this: the three reviews on record were submitted against 23817f25, which predates the rewrite described at the top of the PR body. Nothing reviewed there is still current — the diagnosis, the fix and the title all changed afterwards.

The description has also been updated to say why this is still worth landing now that #455 has fixed one concrete cause of the silent death.

Re-verified after the rebase: cargo clippy --workspace --all-targets -- -D warnings, cargo clippy -p e2e-cucumber --test e2e -- -D warnings, cargo fmt --all --check, cargo test -p e2e-cucumber --lib (131 passed), cargo xtask manifest --check. cargo xtask tpn --check was not re-run — cargo-about is not installed in my sandbox — but the Cargo.lock delta adds only dependency edges to the existing e2e-cucumber entry and no new packages, so THIRD_PARTY_NOTICES.txt cannot change.

@siloteemu

Copy link
Copy Markdown

🔴 Automated review · pr-review-watcher · 6ea166f

This automation never files a GitHub approval, so no approving review will
appear here whatever the outcome — the merge decision stays with a human
reviewer.

Summary

Adds a diagnostic layer to the e2e harness: a catch_unwind boundary around the cucumber run that records an escaping panic to stderr and to harness-diagnostics.log in the results directory, plus an O_NONBLOCK-clearing pass over the suite's own stdio. Outcome: Needs work — the change is well-reasoned and the caught panic is genuinely re-raised, but the two properties the module exists to guarantee are the two with no test behind them. Verified: ran cargo test -p e2e-cucumber --lib in a scratch copy (131 pass) and then 10 single-line mutations of the new production code — 8 were caught, and the two that were not are reported below; confirmed by reading that the Err arm ends in resume_unwind so nothing can now report success where it previously failed, that the recording path cannot panic (every write is discarded via let _) and that the results directory is create_dir_alled before the first write; confirmed the composition claim against the code (the clock-correcting writer is only ever driven inside the new boundary, and its own event handler cannot panic); confirmed the results directory is uploaded as a bare path with no filename glob, so the new log is picked up without a CI change; confirmed futures and libc add dependency edges only, with byte-identical lock entries. Not verified here: the full suite, the e2e suite and the Windows/GPU lanes were not run, and the cucumber-0.23.0 internals the diagnosis rests on (the hook swap at runner/basic.rs:929/:1070 and the writer's panic-on-write-error) could not be read, so the central claim that the silencing is a property of the runner rather than of one bug is unconfirmed either way — the lockfile does pin 0.23.0, matching the citation. No claim is made about the state of the pull request the body references. Leak scan clean; no prompt-injection content found. Blocking: 2 · Non-blocking: 5.

🚫 Blocking (must fix before merge)

  • tests/e2e-cucumber/src/harness_diagnostics.rs:132 (test at :149-164) — the stream snapshot at the moment of the panic has no test. Deleting lines.extend(describe_std_streams()); from record_fatal_panic leaves the entire suite green (verified by mutation). The module doc at :29-31 states the log "records the state of the standard streams at start-up and again at the panic, so a descriptor that changed underneath the process is visible rather than inferred", and the PR text repeats it — that is the module's headline value, and it rests on the second snapshot existing. Worse, the guarding test's own doc comment promises exactly this ("so one read of the artifact shows what changed between them") while its assertions only check the startup note and the panic message. This is the shape where the prose names a guard the code does not prove. Fix: in the_startup_baseline_and_a_later_panic_share_one_log, slice the log at the panic heading and assert the panic section itself carries a stream line — #[cfg(unix)] that the tail contains "stdout ->", #[cfg(not(unix))] that it contains "POSIX-only" — so a silent drop of the second snapshot fails instead of passing.

  • tests/e2e-cucumber/tests/e2e.rs:1306-1320 — the catch boundary, the change's whole point, is untested. Nothing asserts that a panic escaping the run reaches the log, and nothing asserts it is re-raised rather than absorbed. The code is correct as written (resume_unwind diverges, so the process still dies at 101), but "a diagnostic that could swallow a failure" is precisely the risk here and there is no guard against a later edit turning the Err arm into a return. The author's reproduction — a writer that fails after N writes — exists per the PR text but was not committed, and AGENTS.md §3 requires the regression test to ship in the same change. The repo already establishes the remedy: panic_capture, reader_failure and this PR's own blocking_stdio all live in the library target specifically so their logic gets real #[test] coverage (blocking_stdio.rs:37-39 says so outright) — the one piece that matters most was left inline in the harness = false binary instead. Fix: extract the boundary into harness_diagnostics, e.g. pub async fn run_or_record<F: Future>(dir: &Path, fut: F) -> F::Output, have main call it, and unit-test both halves: a panicking future writes the message into the log, and the panic still propagates (assert the re-raise with catch_unwind in the test).

Non-blocking

  • tests/e2e-cucumber/src/harness_diagnostics.rs:192-198 — an_unwritable_destination_is_survived_silently passes vacuously: its only assertion is !missing.exists(), which a mutation that makes append write nothing at all also satisfies. It does catch its named defect (a panic on an unwritable destination), but adding a writable-directory write in the same test would prove the path was exercised.
  • PR text — the --lib gate is cited at .github/workflows/ci.yml:1270; the step is actually at :1325, and that job is Linux-only. Windows coverage of these unit tests comes from cargo test --workspace --all-targets in the Windows job, which is the mechanism the head commit's story actually depends on.
  • PR text — the test-plan line "all three standard streams are described even when nothing is wrong" is stale after the head commit; that now holds only on POSIX, with a placeholder elsewhere.
  • Commit 277fd16's message asserts the non-blocking-stdio root cause as established fact. The later commit corrects the code comments, but git log on blocking_stdio.rs still reads as a diagnosis rather than hardening — worth amending that message before merge so a future bisector isn't handed the refuted cause.
  • tests/e2e-cucumber/src/blocking_stdio.rs:31-35 — clearing O_NONBLOCK mutates the shared open file description and is deliberately never restored, so it also changes semantics for whatever else holds that description. This is documented and argued, and it runs unconditionally on every lane rather than only where a problem was observed; worth a maintainer's explicit sign-off rather than being carried along with the diagnostic.

@siloteemu siloteemu left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 Automated review · pr-review-watcher · 6ea166f

This automation never files a GitHub approval, so no approving review will appear here whatever the outcome — the merge decision stays with a human reviewer.

Two properties this change exists to guarantee have no test behind them, and one of them is the change's whole point.

The catch boundary is untested. tests/e2e-cucumber/tests/e2e.rs:1306-1320 — nothing asserts that a panic escaping the run reaches the log, and nothing asserts it is re-raised rather than absorbed. The code is correct as written, but a diagnostic that could swallow a failure is precisely the risk here, and there is no guard against a later edit turning the Err arm into a return. AGENTS.md §3 asks for the regression test to ship in the same change, and the repo already establishes the remedy — panic_capture, reader_failure and this PR's own blocking_stdio all live in the library target specifically so their logic gets real #[test] coverage. Extracting the boundary into harness_diagnostics (e.g. run_or_record) and unit-testing both halves would close it: a panicking future writes the message into the log, and the panic still propagates.

The panic-time stream snapshot has no test. tests/e2e-cucumber/src/harness_diagnostics.rs:132 — deleting lines.extend(describe_std_streams()); from record_fatal_panic leaves the entire suite green. The module doc at :29-31 states the log records the streams at start-up and again at the panic, and the guarding test's own doc comment promises the same, while its assertions only check the startup note and the panic message. Slicing the log at the panic heading and asserting the panic section carries a stream line would make the sentence true.

The full findings, including five non-blocking items, are in the review comment on this PR.

rominf added a commit that referenced this pull request Sep 29, 2026
cucumber measures every scenario's duration with `SystemTime` rather than a
monotonic clock and panics when the subtraction underflows
(cucumber-0.23.0/src/writer/junit.rs:433, writer/json.rs:218 and :284). A wall
clock that steps backwards by any amount between a scenario's start and finish
therefore kills the run outright. Worse, the panic is raised inside the writer,
which is where cucumber has swapped the panic hook for an empty one, so the job
died mid-suite reporting nothing at all.

That is what this lane has been doing on most runs for days, the merge queue
included. The message was only recovered once the harness began catching the
panic at the run boundary (#445):

  failed to compute duration between SystemTime { tv_sec: 1790582151 } and
  SystemTime { tv_sec: 1790582185 }: second time provided was later than self

The scenario "finished" 33 seconds before it started. Nothing else in the matrix
sees this because nothing else runs in a freshly booted guest whose clock is
still being corrected underneath it.

Land that correction up front, while nothing is timing anything, then stop the
clock being stepped again for the rest of the job. Both sides are touched
because either can be the one that moves: the guest tracks the Windows host's
clock, so a host-side correction lands in the guest too. Every command is
best-effort and the step never fails the lane -- a clock that cannot be settled
should still run and fail with a real diagnosis rather than a red step here.

The step reports what it found on both sides, so if a run still steps, the log
says which side was left able to do it.

Signed-off-by: Roman Inflianskas <Roman.Inflianskas@amd.com>
@rominf
rominf force-pushed the fix/e2e-wsl-nonblocking-stdio branch from 6ea166f to 566aaf9 Compare September 29, 2026 12:52
@rominf

rominf commented Sep 29, 2026

Copy link
Copy Markdown
Collaborator Author

Thanks — both blocking findings were real, and I reproduced each by mutation before fixing it. Addressed in 566aaf93.

History note: the branch is now a single commit rebased onto a3864431. The before/after SHA table in my earlier rebase comment is superseded — 277fd164, 064d7545 and 6ea166f5 no longer exist on the branch.

Blocking

1. The panic-time stream snapshot had no test. Confirmed: deleting lines.extend(describe_std_streams()) from record_fatal_panic left the suite green. The trap is that record_startup emits a snapshot too, so a whole-log contains("stdout ->") would still have passed — the assertion had to be per-section. The test now slices the log at the panic heading and asserts both sections carry a snapshot (#[cfg(unix)] a stream line, otherwise the POSIX placeholder). Re-running your mutation now fails the_startup_baseline_and_a_later_panic_share_one_log.

2. The catch boundary was untested. Extracted to the library target as you suggested — harness_diagnostics::run_or_record(dir, fut) — with main calling it, and two tests: an escaping panic reaches the log and still propagates, and a healthy run passes through untouched.

One wrinkle worth recording. My first version of the panic test used async { panic!(...) }, whose type is !. That made "swallow the panic and return something" a compile error rather than a test failure — so the assert!(escaped.is_err()) guard could never fire, which is the same vacuity you flagged elsewhere. The future now yields a value on its non-panicking path, so the mutation compiles and the assertion actually catches it.

The extraction also tripped clippy::large_futures — an async fn stores the (enormous) cucumber future inline and hands the caller a future of the same size. run_or_record returns a boxed future instead, so the allocation happens once at the boundary and no call site has to know.

Mutations now caught, each by the named test: drop the panic-time snapshot; absorb the panic instead of re-raising; never record the escaping panic; make the log append a no-op (that last one fails three tests, including the previously-vacuous one).

Non-blocking

  • Vacuous an_unwritable_destination_is_survived_silently — correct, !missing.exists() was satisfied by an append that wrote nothing at all. It now also writes to a writable directory in the same test and asserts the log appears, so the no-op mutation fails.

  • ci.yml:1270 — this one is wrong. The --lib step is at :1270; there is exactly one occurrence in the file, and :1325 is the unrelated "Download all E2E reports" step. The substance behind it stands, though, and the PR text now says it: that step lives in the e2e job, which is runs-on: ubuntu-latest, so the gate is Linux-only and the #[cfg(not(unix))] branch is covered by cargo test --workspace --all-targets in the Windows job at :587.

  • Stale "all three standard streams" line — fixed; it now says POSIX, with an explicit placeholder elsewhere.

  • Commit message asserting the refuted root cause — agreed, and a fair thing to catch: git log would have handed a bisector a diagnosis that had already been withdrawn. That commit no longer exists; history was rebuilt so the refuted cause never appears.

  • O_NONBLOCK clearing mutating the shared open file description — dropped entirely rather than sent for sign-off. Two reasons: it fixed nothing observed (the diagnosis it rested on was refuted — that runner's stdio arrives blocking), and its effect escaped the process, since the flag lives on the open file description shared through fork/exec/dup and was deliberately never restored. The diagnostic that remains makes it unnecessary: the flags are recorded at start-up and at the panic, so if a non-blocking descriptor ever does appear, the artifact will say so and a fix can land with evidence instead of ahead of it. That also leaves the PR as one logical change.

Not verified here

cargo xtask tpn --check — cargo-about isn't installed in my sandbox. The lock delta adds only dependency edges to the existing e2e-cucumber entry and no [[package]] blocks, and CI's Third-party notices current check passed on the previous head. The e2e suite itself and the GPU/Windows lanes were not run locally.

@siloteemu

Copy link
Copy Markdown

🔴 Automated review · pr-review-watcher · 566aaf9

This automation never files a GitHub approval, so no approving review will appear here whatever the outcome — the merge decision stays with a human reviewer.

Summary

Adds a panic-catching boundary and a diagnostics log around the cucumber run so a harness death names its own cause instead of exiting 101 in silence; the code is in a mergeable state and both objections from the prior round are discharged. Verified: on a scratch copy, cargo test -p e2e-cucumber --lib harness_diagnostics passes 5/5, and four separate mutations each turn it red — dropping lines.extend(describe_std_streams()) from record_fatal_panic fails the_startup_baseline_and_a_later_panic_share_one_log (the exact mutation the prior round said passed), deleting the record_fatal_panic call in the Err arm fails a_panic_escaping_the_run_is_recorded_and_re_raised, making the boundary absorb the panic (return a default instead of resume_unwind) fails the same test, and making append a no-op fails three; separately, the load-bearing diagnosis was checked against the vendored cucumber-0.23.0 source — the hook is taken and replaced with an empty closure at runner/basic.rs:929-930, the restore at :1070 is a bare straight-line call with no drop guard or catch_unwind around it, the writer runs on the same task and panics on any write error at writer/basic.rs:163, and the JSON/JUnit writers flush only on the Finished event with no Drop fallback, so without this change the suite genuinely stays silent with empty reports. The end-to-end suite itself was not run here. Checks at review time: 6 pending, 2 skipped, 21 success, no failures. Blocking: 0 · Non-blocking: 2.

Item by item against the change request we held:

  • "The catch boundary is untested." Discharged. The boundary moved out of the harness = false binary into tests/e2e-cucumber/src/harness_diagnostics.rs:168 (run_or_record), wired in at tests/e2e-cucumber/tests/e2e.rs:1296, and both halves now have #[test] coverage: harness_diagnostics.rs:273 asserts an escaping panic reaches the log and still propagates, :304 asserts a healthy run passes its value through with no panic section. Not taken on the prose — both the "never recorded" and the "absorbed instead of re-raised" mutations were applied and both fail. The test at :280-286 deliberately gives the inner future a real return value so "swallow and return" is a test failure rather than a compile error, which is what makes the is_err() assertion load-bearing.
  • "The panic-time stream snapshot has no test." Discharged. assert_has_stream_snapshot at harness_diagnostics.rs:194 slices the log at the panic heading and asserts the snapshot per section rather than over the whole file, so the start-up snapshot can no longer satisfy the panic-side claim. Confirmed by mutation: the module doc at :31-33 and the test doc now both hold.

🚫 Blocking (must fix before merge)

None.

Non-blocking

  • PR description, test-plan section — the --lib step is cited as .github/workflows/ci.yml:1270; the step is actually at :1325 (:1270 is a comment inside the same job's header). The job and its Linux runner are as described, and the Windows reference at :587 is exact; only this one line number is off.
  • tests/e2e-cucumber/src/harness_diagnostics.rs:78-86 — the "what each descriptor points at" half of the snapshot is /proc-based and so is Linux-only inside a cfg(unix) branch; it degrades to target unknown (...) elsewhere, which is handled, but the flags half remains the portable part.

@siloteemu
siloteemu dismissed their stale review September 29, 2026 14:09

Both objections are discharged at 566aaf9. The catch boundary now lives in a testable module and has coverage on both halves, and the panic-time stream snapshot is asserted per section rather than over the whole log. Verified by mutation: four separate single-line mutations each turn the new tests red, including the exact one the previous round said passed. Withdrawing; the current round is posted as a comment.

…ilently

The self-hosted WSL2 lane stops mid-suite with nothing to go on: the last
line is a passing step, then cargo's "error: test failed" with no
"Caused by:", no panic message anywhere, and report.json/junit.xml left at
zero bytes with no report.html. Every guess at the cause costs a full CI
round trip on a scarce runner.

cucumber's runner replaces the panic hook with an empty one for the whole
run and restores it afterwards (cucumber-0.23.0 runner/basic.rs:929,
restored at :1070) so a step's panic is reported by the writer rather than
printed twice. A panic raised by the writer itself unwinds out of run()
past that restore with the silencing hook still installed: nothing prints
and the exit code is all that survives. That is a property of the runner,
not of any one lane or bug, which is why every failure of this shape has
been unreadable.

Catch it where it escapes and record it to stderr and to a log inside the
results directory the lane already uploads, then re-raise, so the process
still dies with 101 and nothing downstream has to learn a new signal. The
log also carries the state of the standard streams at start-up and again
at the panic, so a descriptor replaced underneath the process is visible
rather than inferred; it only reads those streams and never modifies them.

The boundary lives in the library target rather than inline in the
harness = false binary so it gets real #[test] coverage: an escaping panic
reaches the log and still propagates, a healthy run passes through
untouched, and both stream snapshots are asserted per section, so dropping
the panic-time one fails instead of passing on the start-up one.

Signed-off-by: Roman Inflianskas <Roman.Inflianskas@amd.com>
@rominf
rominf force-pushed the fix/e2e-wsl-nonblocking-stdio branch from 566aaf9 to 9f33b14 Compare September 30, 2026 06:28
@rominf
rominf enabled auto-merge September 30, 2026 07:25
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants