From 9f33b1443df81563c636d6864a292d589aed0c91 Mon Sep 17 00:00:00 2001 From: Roman Inflianskas Date: Tue, 29 Sep 2026 12:17:08 +0000 Subject: [PATCH 1/2] fix(e2e): surface the panic that kills the suite instead of exiting silently 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 --- Cargo.lock | 1 + tests/e2e-cucumber/Cargo.toml | 12 +- tests/e2e-cucumber/src/harness_diagnostics.rs | 316 ++++++++++++++++++ tests/e2e-cucumber/src/lib.rs | 1 + tests/e2e-cucumber/tests/e2e.rs | 14 +- 5 files changed, 340 insertions(+), 4 deletions(-) create mode 100644 tests/e2e-cucumber/src/harness_diagnostics.rs diff --git a/Cargo.lock b/Cargo.lock index 531d21b17..e3abf58b6 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1270,6 +1270,7 @@ dependencies = [ "cucumber", "e2e-report", "futures", + "libc", "portable-pty", "rand 0.9.4", "reqwest 0.13.4", diff --git a/tests/e2e-cucumber/Cargo.toml b/tests/e2e-cucumber/Cargo.toml index 89e1e6541..0c7469b49 100644 --- a/tests/e2e-cucumber/Cargo.toml +++ b/tests/e2e-cucumber/Cargo.toml @@ -26,7 +26,11 @@ path = "src/bin/fake-tailscale.rs" axum.workspace = true cucumber = { version = "0.23", features = ["output-json", "output-junit"] } e2e-report = { path = "../../crates/e2e-report" } -# Builds the paced download fixture's chunked response body (`stream::unfold`). +# Two users: it builds the paced download fixture's chunked response body +# (`stream::unfold`), and it provides `FutureExt::catch_unwind`, which catches a +# panic escaping the cucumber run (see `src/harness_diagnostics.rs`) — plain +# `std::panic::catch_unwind` cannot span an `.await`. cucumber already pulls this +# in, so it adds no crate to the tree. futures = "0.3" # Drive the interactive dash TUI black-box: spawn the real `rocm` binary under a # pseudo-terminal (`portable-pty`, cross-platform openpty/ConPTY) and parse the @@ -50,6 +54,12 @@ tower-http = { version = "0.6", features = ["fs"] } url = "2" vt100 = "0.16" +# `fcntl(F_GETFL)` only, to read (never modify) the `O_NONBLOCK` state of the +# suite's own stdio for the diagnostics log (see `src/harness_diagnostics.rs`). +# Already a workspace dependency, so this adds no new crate to the tree. +[target.'cfg(unix)'.dependencies] +libc.workspace = true + [[test]] name = "e2e" harness = false diff --git a/tests/e2e-cucumber/src/harness_diagnostics.rs b/tests/e2e-cucumber/src/harness_diagnostics.rs new file mode 100644 index 000000000..db0ff8555 --- /dev/null +++ b/tests/e2e-cucumber/src/harness_diagnostics.rs @@ -0,0 +1,316 @@ +// Copyright © Advanced Micro Devices, Inc., or its affiliates. +// +// SPDX-License-Identifier: MIT + +//! Make the harness's own death legible instead of silent. +//! +//! The self-hosted WSL2 lane fails by stopping mid-suite with nothing to go on: the +//! last line is a passing step, then `cargo`'s `error: test failed` with no +//! `Caused by:` — which narrows it to exit code 101, an unwinding panic — and no +//! panic message anywhere in the job log. `report.json` and `junit.xml` are left at +//! zero bytes and `report.html` is never written, so the artifact says nothing +//! either. Every guess at the cause costs a full CI round trip on a scarce runner. +//! +//! **Why the message is missing.** cucumber's runner replaces the panic hook with +//! an empty one for the whole run and restores it afterwards +//! (`cucumber-0.23.0/src/runner/basic.rs:929`, restored at `:1070`) — deliberately, +//! so a step's panic is reported by the writer rather than printed twice. A panic +//! *raised by the writer itself* escapes that path: it unwinds out of `run()` past +//! the restore, with the silencing hook still installed. Nothing prints, and the +//! exit code is all that is left. That is not specific to any lane; it is why every +//! failure of this shape has been unreadable. +//! +//! So this does not install a hook — one would be taken away again on the next +//! line. [`run_or_record`] catches the panic where it escapes, at the `run()` +//! boundary, and records it two ways: to stderr, which the silenced hook would have +//! written, and to a log inside the results directory the lane already uploads, +//! which survives even if stderr is the thing that broke. The panic is then +//! re-raised, so the process still dies with 101 and nothing downstream has to +//! learn a new signal. +//! +//! The same 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. This only observes the streams; it does not modify them. +//! +//! The whole boundary lives in the library target rather than inline in the +//! `harness = false` cucumber test binary, so its logic gets real `#[test]` +//! coverage — the custom harness never executes plain `#[test]` functions placed +//! inside it. Same reason as [`crate::panic_capture`]. + +use std::future::Future; +use std::io::Write as _; +use std::path::Path; +use std::pin::Pin; + +use futures::FutureExt as _; + +/// Name of the log inside the results directory. Picked up by the lane's existing +/// `upload-artifact` of the whole directory, so nothing in CI needs to change. +pub const LOG_NAME: &str = "harness-diagnostics.log"; + +/// Describe the standard streams: their `O_NONBLOCK` state and what they point at. +/// +/// Read-only. Best-effort and infallible — a description that cannot be obtained is +/// reported as such, because this runs on a path where failing would destroy the +/// very diagnostic it exists to produce. +#[must_use] +pub fn describe_std_streams() -> Vec { + #[cfg(unix)] + { + use std::os::fd::{AsFd as _, AsRawFd as _, BorrowedFd}; + + #[allow(unsafe_code)] // libc FFI + fn flags(fd: BorrowedFd<'_>) -> String { + // SAFETY: `fd` is a valid borrowed descriptor; `F_GETFL` takes no + // pointer arguments. + let raw = unsafe { libc::fcntl(fd.as_raw_fd(), libc::F_GETFL) }; + if raw < 0 { + return format!("flags unreadable ({})", std::io::Error::last_os_error()); + } + let blocking = if raw & libc::O_NONBLOCK == 0 { + "blocking" + } else { + "NON-BLOCKING" + }; + format!("{blocking} (F_GETFL=0o{raw:o})") + } + + // `/proc/self/fd/N` names the open file the descriptor currently refers to + // ("pipe:[12345]", a tty, a path). Two snapshots naming different targets + // is the signature of a descriptor being replaced underneath the process. + fn target(n: i32) -> String { + std::fs::read_link(format!("/proc/self/fd/{n}")).map_or_else( + |e| format!("target unknown ({e})"), + |p| p.display().to_string(), + ) + } + + let stdin = std::io::stdin(); + let stdout = std::io::stdout(); + let stderr = std::io::stderr(); + vec![ + format!("stdin -> {} [{}]", target(0), flags(stdin.as_fd())), + format!("stdout -> {} [{}]", target(1), flags(stdout.as_fd())), + format!("stderr -> {} [{}]", target(2), flags(stderr.as_fd())), + ] + } + #[cfg(not(unix))] + { + vec!["stream description is POSIX-only; not collected on this platform".to_owned()] + } +} + +/// Append a section to the diagnostics log, creating it if needed. +/// +/// Silently gives up on any I/O error: a diagnostic must never be the reason a run +/// fails, and there is nowhere left to report the failure of the reporting channel. +fn append(dir: &Path, heading: &str, lines: &[String]) { + let Ok(mut file) = std::fs::OpenOptions::new() + .create(true) + .append(true) + .open(dir.join(LOG_NAME)) + else { + return; + }; + let _ = writeln!(file, "=== {heading} ==="); + for line in lines { + let _ = writeln!(file, "{line}"); + } + let _ = writeln!(file); + let _ = file.flush(); +} + +/// Record the run's starting conditions. +/// +/// Written unconditionally — not only when something looks wrong. A successful run +/// leaves the baseline the next failing run is read against, and "checked, nothing +/// to report" is a different fact from "never ran". +pub fn record_startup(dir: &Path) { + append(dir, "harness start", &describe_std_streams()); +} + +/// Record a panic that escaped the cucumber run, to the log and to stderr. +/// +/// Both destinations on purpose: stderr is what a reader of the job log expects and +/// is what the silenced hook would have produced, while the log survives a stderr +/// that is not reaching anyone. `writeln!` rather than `eprintln!` so a failing +/// stderr yields a missing line rather than a second panic on the way out. +pub fn record_fatal_panic(dir: &Path, message: &str) { + let mut lines = vec![format!("message: {message}")]; + lines.extend(describe_std_streams()); + append(dir, "fatal panic (escaped the cucumber run)", &lines); + + let _ = writeln!( + std::io::stderr(), + "E2E suite aborted by a panic inside the cucumber run: {message}\n\ + (cucumber silences the panic hook while running, so this would otherwise \ + print nothing; see {LOG_NAME} in the results artifact)" + ); +} + +/// Drive `fut` to completion, recording any panic that escapes it before re-raising. +/// +/// This is the boundary described in the module docs: the last point at which the +/// payload of a writer panic still exists, because cucumber's silencing hook is +/// still installed as it unwinds past the restore. +/// +/// The panic is **re-raised, never absorbed** — `resume_unwind` diverges, so the +/// process still dies with exit 101 exactly as it did before. A diagnostic that +/// swallowed a failure would turn a red run green, which is strictly worse than the +/// silence it replaces. +/// +/// `std::panic::catch_unwind` cannot span an `.await`, hence `FutureExt`. +/// +/// Returns a boxed future rather than being an `async fn`: the cucumber run it +/// wraps is enormous, and an `async fn` would store it inline and hand the caller a +/// future of the same size (`clippy::large_futures`). Allocating it once here keeps +/// that detail out of every call site. +pub fn run_or_record<'a, F>(dir: &'a Path, fut: F) -> Pin + 'a>> +where + F: Future + 'a, +{ + Box::pin(async move { + let guarded = Box::pin(std::panic::AssertUnwindSafe(fut).catch_unwind()); + match guarded.await { + Ok(output) => output, + Err(payload) => { + record_fatal_panic(dir, &crate::panic_capture::panic_message(&payload)); + std::panic::resume_unwind(payload); + } + } + }) +} + +#[cfg(test)] +mod tests { + use super::*; + + /// The stream snapshot the module promises at *both* ends of the log. + /// + /// Asserted per-section rather than over the whole file: `record_startup` also + /// emits one, so a whole-log `contains` would still pass if the panic-time + /// snapshot were dropped — which is the headline claim (comparing the two is + /// how a descriptor replaced mid-run becomes visible). + fn assert_has_stream_snapshot(section: &str, which: &str, log: &str) { + #[cfg(unix)] + let (needle, what) = ("stdout ->", "a stream line"); + #[cfg(not(unix))] + let (needle, what) = ("POSIX-only", "the POSIX-only placeholder"); + assert!( + section.contains(needle), + "the {which} section carries no stream snapshot ({what} expected):\n{log}" + ); + } + + /// Start-up state and a later fatal panic have to land in the same file, in + /// order, so one read of the artifact shows what changed between them. + #[test] + fn the_startup_baseline_and_a_later_panic_share_one_log() { + let dir = tempfile::tempdir().expect("failed to create a temp dir"); + record_startup(dir.path()); + record_fatal_panic(dir.path(), "failed to write into terminal: boom"); + + let log = std::fs::read_to_string(dir.path().join(LOG_NAME)).expect("no log written"); + let start = log.find("=== harness start ===").expect("no start section"); + let panic_at = log.find("=== fatal panic").expect("no panic section"); + assert!(start < panic_at, "sections out of order:\n{log}"); + assert!( + log.contains("message: failed to write into terminal: boom"), + "{log}" + ); + + let (startup_section, panic_section) = log.split_at(panic_at); + assert_has_stream_snapshot(startup_section, "start-up", &log); + assert_has_stream_snapshot(panic_section, "panic", &log); + } + + /// Every stream is named even when nothing is wrong, so a later reader can tell + /// "checked, was fine" from "never collected" — and where the flags are POSIX + /// only, the log has to say that rather than go quiet, which reads the same as + /// a collection that never ran. + #[test] + fn the_stream_description_accounts_for_every_standard_stream() { + let described = describe_std_streams().join("\n"); + assert!(!described.is_empty(), "the description must never be empty"); + + #[cfg(unix)] + for stream in ["stdin", "stdout", "stderr"] { + assert!( + described.contains(stream), + "{stream} missing from: {described}" + ); + } + #[cfg(not(unix))] + assert!( + described.contains("POSIX-only"), + "a platform without these flags must say so, got: {described}" + ); + } + + /// A destination that cannot be written to must not take the run down with it — + /// this runs on the path that is already handling a fatal panic. + #[test] + fn an_unwritable_destination_is_survived_silently() { + let dir = tempfile::tempdir().expect("failed to create a temp dir"); + let missing = dir.path().join("does").join("not").join("exist"); + record_startup(&missing); + record_fatal_panic(&missing, "boom"); + assert!(!missing.exists(), "the helper must not create the tree"); + + // Prove those calls were real work that the unwritable path swallowed, and + // not a no-op: without this, an `append` that wrote nothing anywhere would + // satisfy the assertion above just as well. + record_startup(dir.path()); + assert!( + dir.path().join(LOG_NAME).exists(), + "a writable destination must still be written" + ); + } + + /// The boundary's whole purpose: the message survives, and the failure still + /// fails. Absorbing the panic would turn a red run green. + #[tokio::test] + async fn a_panic_escaping_the_run_is_recorded_and_re_raised() { + let dir = tempfile::tempdir().expect("failed to create a temp dir"); + + // The future yields a value on its non-panicking path, as the real one + // does. Without that, the block's type is `!`, which makes "swallow the + // panic and return something" a compile error rather than a test failure — + // and an assertion that no reachable mutation can trip is not a guard. + let escaped = std::panic::AssertUnwindSafe(run_or_record(dir.path(), async { + assert!( + !std::hint::black_box(true), + "failed to write into terminal: injected" + ); + "a summary that is never produced" + })) + .catch_unwind() + .await; + + assert!( + escaped.is_err(), + "the panic must propagate, not be absorbed into a normal return" + ); + let log = std::fs::read_to_string(dir.path().join(LOG_NAME)).expect("no log written"); + assert!( + log.contains("message: failed to write into terminal: injected"), + "the escaping panic's message must reach the log:\n{log}" + ); + } + + /// A run that completes normally passes straight through — the boundary must + /// not alter the value or leave a panic section behind on a healthy run. + #[tokio::test] + async fn a_run_that_does_not_panic_is_passed_through_untouched() { + let dir = tempfile::tempdir().expect("failed to create a temp dir"); + + let summary = run_or_record(dir.path(), async { "the real summary" }).await; + + assert_eq!(summary, "the real summary"); + let log = std::fs::read_to_string(dir.path().join(LOG_NAME)).unwrap_or_default(); + assert!( + !log.contains("fatal panic"), + "a healthy run must not record a panic:\n{log}" + ); + } +} diff --git a/tests/e2e-cucumber/src/lib.rs b/tests/e2e-cucumber/src/lib.rs index f82bde9f6..97ae7e2e1 100644 --- a/tests/e2e-cucumber/src/lib.rs +++ b/tests/e2e-cucumber/src/lib.rs @@ -4,6 +4,7 @@ pub mod capability; pub mod expectation; +pub mod harness_diagnostics; pub mod http_server; pub mod installer_fixture; pub mod loopback_http; diff --git a/tests/e2e-cucumber/tests/e2e.rs b/tests/e2e-cucumber/tests/e2e.rs index 638d33541..d7dbed9d7 100644 --- a/tests/e2e-cucumber/tests/e2e.rs +++ b/tests/e2e-cucumber/tests/e2e.rs @@ -1122,6 +1122,10 @@ async fn main() { use e2e_cucumber::monotonic_clock::MonotonicClockWriter; let dir = results_dir(); + + // Baseline for the diagnostics log the lane uploads; see the `run()` boundary + // below and `harness_diagnostics` for what it is answering. + e2e_cucumber::harness_diagnostics::record_startup(&dir); let json_file = std::fs::File::create(dir.join("report.json")).expect("failed to create report.json"); let junit_file = @@ -1206,7 +1210,11 @@ async fn main() { } else { 64 }; - let summary = E2eWorld::cucumber() + // Wrapped, not hooked — see `harness_diagnostics::run_or_record`, which this is + // handed to below. cucumber replaces the panic hook with an empty one for the + // whole run, so a panic raised by the *writer* unwinds out of here with that + // silencing hook still installed and prints nothing at all. + let cucumber_run = E2eWorld::cucumber() .max_concurrent_scenarios(max_concurrent) // Record the scenario name on the World before each scenario so every // `rocm` invocation can be tied back to its scenario for the coverage @@ -1291,8 +1299,8 @@ async fn main() { } run } - }) - .await; + }); + let summary = e2e_cucumber::harness_diagnostics::run_or_record(&dir, cucumber_run).await; // Generate the HTML report before exiting so the artifact still uploads on // failure. From a0e08c6a09dcf13e1c9e3646b00a1f8807bfab05 Mon Sep 17 00:00:00 2001 From: Roman Inflianskas Date: Thu, 1 Oct 2026 10:31:01 +0000 Subject: [PATCH 2/2] test(e2e): pin the stderr half of the fatal-panic boundary Deleting the whole stderr write left all five tests in the module green. That is the destination the lane this change exists for actually reads: stderr reaches the job log, and the suite lane publishes no artifact at all, so there the log is unreachable and that line is the entire diagnostic. Unpinned, a later simplification could drop it and restore the exact silence being removed, with the suite still green. Inject the destination instead of hard-coding `std::io::stderr()`: `record_fatal_panic` becomes a wrapper over a private `record_fatal_panic_to`, and the new test drives it with a `Vec`, asserting both the panic message and the pointer to the log. Keeps `writeln!` rather than `eprintln!`, so a failing stderr still yields a missing line rather than a second panic; adds no platform gate and no further `unsafe`. Mutation-checked: removing the write fails this test and only this test. Signed-off-by: Roman Inflianskas --- tests/e2e-cucumber/src/harness_diagnostics.rs | 42 ++++++++++++++++++- 1 file changed, 41 insertions(+), 1 deletion(-) diff --git a/tests/e2e-cucumber/src/harness_diagnostics.rs b/tests/e2e-cucumber/src/harness_diagnostics.rs index db0ff8555..f83b8e3e9 100644 --- a/tests/e2e-cucumber/src/harness_diagnostics.rs +++ b/tests/e2e-cucumber/src/harness_diagnostics.rs @@ -136,12 +136,23 @@ pub fn record_startup(dir: &Path) { /// that is not reaching anyone. `writeln!` rather than `eprintln!` so a failing /// stderr yields a missing line rather than a second panic on the way out. pub fn record_fatal_panic(dir: &Path, message: &str) { + record_fatal_panic_to(dir, message, &mut std::io::stderr()); +} + +/// [`record_fatal_panic`] with its second destination injected, so the text written +/// there can be asserted on. +/// +/// Split out purely for that: with `std::io::stderr()` hard-coded, deleting the +/// write left every test in this module green, which is the one destination the +/// lane this exists for actually reads. The pointer to the log is the part a reader +/// needs and the part most likely to rot, so it is what the test pins. +fn record_fatal_panic_to(dir: &Path, message: &str, out: &mut dyn std::io::Write) { let mut lines = vec![format!("message: {message}")]; lines.extend(describe_std_streams()); append(dir, "fatal panic (escaped the cucumber run)", &lines); let _ = writeln!( - std::io::stderr(), + out, "E2E suite aborted by a panic inside the cucumber run: {message}\n\ (cucumber silences the panic hook while running, so this would otherwise \ print nothing; see {LOG_NAME} in the results artifact)" @@ -298,6 +309,35 @@ mod tests { ); } + /// The second destination is the one the lane actually reads. + /// + /// stderr is what reaches the job log, and the suite lane this boundary exists + /// for publishes no artifact at all — so the log is unreachable there and this + /// line is the whole diagnostic. Left unasserted, deleting the write kept every + /// other test in this module green, which would quietly restore exactly the + /// silence the change removes. + /// + /// Pins the pointer to the log as well as the message: a reader who gets this + /// line still needs to be told where the fuller record is, and that is the half + /// most likely to rot. + #[test] + fn the_panic_is_announced_on_the_second_destination_too() { + let dir = tempfile::tempdir().expect("failed to create a temp dir"); + let mut out = Vec::new(); + + record_fatal_panic_to(dir.path(), "failed to write into terminal: boom", &mut out); + + let written = String::from_utf8(out).expect("the announcement must be UTF-8"); + assert!( + written.contains("failed to write into terminal: boom"), + "the panic message must reach the second destination, got: {written}" + ); + assert!( + written.contains(LOG_NAME), + "the announcement must point at the fuller record, got: {written}" + ); + } + /// A run that completes normally passes straight through — the boundary must /// not alter the value or leave a panic section behind on a healthy run. #[tokio::test]