test(testkit): fail stalled steps before the runner stops the test

tests/runner/src/collect-k3s.sh

@@ -28,6 +28,27 @@ collect_log() {
   printf '\ncommand status: %s\n' "${PIPESTATUS[0]}"
 }
 
+# Gateway logs cover the whole run, so a failing test's window is included.
+# The runner records when the run started; without that, use a fixed window.
+# The tail is larger than for other logs because a gateway logs many lines.
+RUN_STARTED_FILE=/var/tmp/openshell-run-started
+log_since=--since=30m
+if run_started=$(cat "$RUN_STARTED_FILE" 2>/dev/null) &&
+  [[ $run_started =~ ^[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}Z$ ]]; then
+  log_since=--since-time=$run_started
+fi
+
+collect_gateway_log() {
+  printf '\n### %s (%s)\n' "$1" "$log_since"
+  shift
+  timeout 20s "$@" 2>&1 | {
+    head -c 65536
+    printf '\n### Remaining log tail\n'
+    tail -c 524288
+  }
+  printf '\ncommand status: %s\n' "${PIPESTATUS[0]}"
+}
+
 {
   date --utc --iso-8601=seconds
   collect 'K3s service state' systemctl show k3s.service \
@@ -74,8 +95,8 @@ collect_log() {
   mapfile -t gateway_pods < <(timeout 10s /usr/local/bin/k3s kubectl --request-timeout=5s -n openshell get pods \
     --selector app.kubernetes.io/name=openshell,app.kubernetes.io/instance=openshell --output name 2>/dev/null)
   for pod in "${gateway_pods[@]}"; do
-    collect "Gateway current logs ($pod)" /usr/local/bin/k3s kubectl --request-timeout=5s -n openshell logs "$pod" -c openshell-gateway --tail=300 --timestamps
-    collect "Gateway previous logs ($pod)" /usr/local/bin/k3s kubectl --request-timeout=5s -n openshell logs "$pod" -c openshell-gateway --previous --tail=300 --timestamps
+    collect_gateway_log "Gateway current logs ($pod)" /usr/local/bin/k3s kubectl --request-timeout=5s -n openshell logs "$pod" -c openshell-gateway "$log_since" --timestamps
+    collect_gateway_log "Gateway previous logs ($pod)" /usr/local/bin/k3s kubectl --request-timeout=5s -n openshell logs "$pod" -c openshell-gateway --previous "$log_since" --timestamps
   done
   collect 'Memory' free -m
   collect 'Disk' df -h / /var/lib/rancher/k3s

tests/runner/src/execute.rs

@@ -42,6 +42,9 @@ const READY_SLACK: Duration = Duration::from_mins(1);
 const NEXTEST_TEST_FAILED: i32 = 100;
 /// nextest's exit code when `--no-tests fail` found no tests to run.
 const NEXTEST_NO_TESTS_RUN: i32 = 4;
+/// The variable that tells a test its per-test limit; testkit reads it
+/// (`openshell_testkit::TIMEOUT_ENV`).
+const TEST_TIMEOUT_ENV: &str = "OPENSHELL_TEST_TIMEOUT_SECS";
 /// How long a stopped test has between SIGTERM and SIGKILL. Matches nextest's
 /// default, so both kinds of bundle stop a hung test the same way.
 const TEST_GRACE_SECS: u64 = 10;
@@ -313,7 +316,10 @@ async fn run_tests(session: &Session, run: &Run<'_>) -> Result<Status> {
     let config = format!("{guest}/nextest.toml");
     let timeout = TEST_TIMEOUT_SECS.to_string();
     let grace = TEST_GRACE_SECS.to_string();
-    let mut tests = vec!["env"];
+    // Each test is told its own limit, so a stuck step fails with its own
+    // error before the runner stops the test.
+    let budget = format!("{TEST_TIMEOUT_ENV}={TEST_TIMEOUT_SECS}");
+    let mut tests = vec!["env", budget.as_str()];
     tests.extend(env.iter().map(String::as_str));
     match kind {
         Kind::Nextest => {
@@ -371,7 +377,7 @@ async fn run_tests(session: &Session, run: &Run<'_>) -> Result<Status> {
     // can be credentials, never appear in the command (or its errors).
     let log = format!("{guest}/{NEXTEST_LOG}");
     let script = format!(
-        r#"exec >"$0" 2>&1; {}; exec "$@""#,
+        r#"exec >"$0" 2>&1; date -u +%Y-%m-%dT%H:%M:%SZ >{RUN_STARTED_FILE} || true; {}; exec "$@""#,
         test_env::export_script(test_env::ENV_DIR)
     );
     let mut command = vec!["sh", "-c", &script, &log];
@@ -441,6 +447,9 @@ const WAIT_K3S_CONTROLLER: &str = include_str!("wait-k3s-controller.sh");
 /// The script retries for up to ten minutes; this catches one that stalls.
 const WAIT_K3S_CONTROLLER_TIMEOUT: Duration = Duration::from_mins(12);
 
+/// Where the run records when it started, in RFC 3339 UTC. The k3s diagnostics
+/// read it (see `collect-k3s.sh`) to collect the gateway's logs from then on.
+const RUN_STARTED_FILE: &str = "/var/tmp/openshell-run-started";
 /// Where the guest keeps the script's output until it is copied out.
 const COLLECT_K3S_OUTPUT: &str = "/var/tmp/openshell-k3s-diagnostics.txt";
 /// How long the guest lets the script run before stopping it. The script
@@ -550,6 +559,11 @@ mod tests {
         assert!(matches!(status(2), Status::Error(_)));
     }
 
+    #[test]
+    fn k3s_diagnostics_read_the_file_the_run_writes() {
+        assert!(COLLECT_K3S.contains(RUN_STARTED_FILE));
+    }
+
     #[test]
     fn k3s_diagnostics_keep_everything_the_old_playbook_collected() {
         for wanted in [
@@ -576,6 +590,7 @@ mod tests {
             "free -m",
             "df -h",
             "[REDACTED]",
+            "--since-time",
         ] {
             assert!(COLLECT_K3S.contains(wanted), "missing {wanted:?}");
         }

tests/testkit/README.md

@@ -122,6 +122,14 @@ plaintext and mTLS gateways. `OPENSHELL_WORKSPACE` selects the workspace
 (default `openshell` on PATH). The CLI always targets the same gateway and
 workspace as the SDK. Each test logs the gateway it used.
 
+`OPENSHELL_TEST_TIMEOUT_SECS` is the time one test may take, as the runner
+enforces it. The runner sets it. When set, `cx.cli`, `cx.exec` and the wait
+helpers give up about five seconds before that limit, with their own error,
+instead of leaving the test to be stopped. When unset, as under plain
+`cargo test`, each step keeps its own timeout. A CLI command that runs longer
+than ten seconds, exits non-zero, or is still running after 30 seconds is
+reported on stderr; fast successful commands print nothing.
+
 Wait for the gateway, then run a suite. Run tests that share a gateway one at
 a time:
 

tests/testkit/testkit/Cargo.toml

@@ -30,7 +30,7 @@ serde = { version = "1", features = ["derive"] }
 serde_json = "1"
 serde_yml = { package = "noyalib", version = "0.0.53", default-features = false, features = ["std", "compat-serde-yaml"] }
 tempfile = "3"
-tokio = { version = "1.43", features = ["macros", "process", "rt", "time"] }
+tokio = { version = "1.43", features = ["io-util", "macros", "process", "rt", "time"] }
 tonic = "0.14"
 
 [target.'cfg(unix)'.dependencies]

tests/testkit/testkit/src/budget.rs

@@ -0,0 +1,98 @@
+// SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
+// SPDX-License-Identifier: Apache-2.0
+
+//! The time one test may take, so a stuck step fails with its own error
+//! before whoever runs the tests stops the test with a generic timeout.
+//!
+//! The runner exports the limit it enforces in [`TIMEOUT_ENV`]. Without it,
+//! as when a test runs under plain `cargo test`, nothing is capped and each
+//! step keeps its own timeout.
+
+use std::sync::OnceLock;
+use std::sync::atomic::{AtomicBool, Ordering};
+use std::time::{Duration, Instant};
+
+/// The per-test limit the runner enforces, in seconds.
+pub const TIMEOUT_ENV: &str = "OPENSHELL_TEST_TIMEOUT_SECS";
+
+/// How long before the limit a step gives up, so its error is reported and
+/// the test cleans up before the runner stops it.
+const MARGIN: Duration = Duration::from_secs(5);
+
+/// The least a step is given, so it still reports a timeout of its own.
+const FLOOR: Duration = Duration::from_secs(1);
+
+/// Set once the test body is over: cleanup needs its own timeouts, because it
+/// is most needed when the budget ran out.
+static RELEASED: AtomicBool = AtomicBool::new(false);
+
+static DEADLINE: OnceLock<Option<Instant>> = OnceLock::new();
+
+/// Start the clock for the current test. Call once, when the test starts.
+pub(crate) fn start() {
+    DEADLINE.get_or_init(|| deadline_from(std::env::var(TIMEOUT_ENV).ok().as_deref()));
+}
+
+/// Stop capping, for cleanup.
+pub(crate) fn release() {
+    RELEASED.store(true, Ordering::Relaxed);
+}
+
+fn deadline_from(value: Option<&str>) -> Option<Instant> {
+    let secs: u64 = value?.trim().parse().ok().filter(|secs| *secs > 0)?;
+    Instant::now().checked_add(Duration::from_secs(secs).saturating_sub(MARGIN))
+}
+
+/// `timeout`, or the time left in the test's budget if that is less.
+pub(crate) fn cap(timeout: Duration) -> Duration {
+    if RELEASED.load(Ordering::Relaxed) {
+        return timeout;
+    }
+    cap_at(timeout, DEADLINE.get().copied().flatten())
+}
+
+fn cap_at(timeout: Duration, deadline: Option<Instant>) -> Duration {
+    match deadline {
+        Some(deadline) => timeout.min(
+            deadline
+                .saturating_duration_since(Instant::now())
+                .max(FLOOR),
+        ),
+        None => timeout,
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    #[test]
+    fn no_limit_leaves_the_timeout_alone() {
+        assert_eq!(deadline_from(None), None);
+        assert_eq!(deadline_from(Some("soon")), None);
+        assert_eq!(deadline_from(Some("0")), None);
+        assert_eq!(
+            cap_at(Duration::from_secs(300), None),
+            Duration::from_secs(300)
+        );
+    }
+
+    #[test]
+    fn a_step_gets_no_more_than_the_time_left() {
+        let deadline = deadline_from(Some("120")).unwrap();
+        let capped = cap_at(Duration::from_secs(300), Some(deadline));
+        assert!(capped <= Duration::from_secs(115), "{capped:?}");
+        assert!(capped > Duration::from_secs(100), "{capped:?}");
+        // A short step keeps its own timeout.
+        assert_eq!(
+            cap_at(Duration::from_secs(10), Some(deadline)),
+            Duration::from_secs(10)
+        );
+    }
+
+    #[test]
+    fn an_exhausted_budget_still_leaves_a_floor() {
+        let passed = Instant::now();
+        assert_eq!(cap_at(Duration::from_secs(300), Some(passed)), FLOOR);
+    }
+}