agent::rung_c_sigkill_... hangs on Linux runners ~half the time, costing 30min and cancelling the job

[kjgbot]

Not the rare flake I first called it. It has now hit roughly half of the runs that reach it, and each hit burns the full 30-minute job budget and cancels every later step — so the SDK suite never runs at all on those.

Signature

06:17:00  test agent::rung_c_sigkill_boundaries_resume_only_unfinished_steps_via_real_cli
            has been running for over 60 seconds
06:42:29  ##[error]The operation was canceled.

Test kernel reaches 30m15s / 30m16s and dies. When healthy, the whole crash_resume binary — all 34 tests including this one — finishes in 38 seconds.

Tally of runs that reached the test

run	branch	outcome
33843408251	feat/tick-runner-0903 (#157)	passed the test (38s binary)
33843430434	feat/v2-surface-package (#134)	passed the test (38s binary)
33843397637	feat/v2-gate-contract (#139)	hung, cancelled 30m15s
33844679490 (1st)	fix/155-crash-skips-backoff (#158)	hung, cancelled 30m16s
33844679490 (rerun)	same commit	passed, whole job 6m46s
33847657688	ci/analyzer-skip-0904 (#159)	Test kernel in progress 16+ min at time of writing

Same commit both hung and passed (#158), which rules out any particular branch and rules out my own suspicion that the kernel-touching PRs were at fault — I asserted that on #139 and have corrected it there.

Not reproducible locally

macOS, this repo, on the #158 branch:

• crash_resume full binary: PASS in 37–47s, 34/34, at default parallelism, --test-threads=4, and --test-threads=2;
• the test alone: 3/3 PASS in ~1s.

So it is specific to the Linux runner, not to thread count and not to the test in isolation.

Why it matters more than a flaky test normally would

1. It is not a failure, it is a hang. The job burns its whole budget, then cancels — 30 minutes per hit.
2. Cancellation skips Install SDK dependencies and everything after, so a hit means the SDK suite does not run at all. A PR can look "checked" while two thirds of the gate never executed.
3. At roughly 50% it will hit most PRs on first try, so the practical cost is a re-run cycle on nearly everything.

This was invisible before #153, because the kernel suite never ran in CI.

Suggested direction, not a fix

The test drives kill/resume boundaries against a real CLI. A resume path waiting on something that never arrives — a process that does not reap, a socket read with no deadline, a lease that is never released — fits the evidence. Worth adding a hard per-test timeout so the failure is a fast red with a backtrace instead of a 30-minute cancellation, independent of the root cause; the diagnosis is much easier from a panic than from a killed job.

Found while landing #154/#158/#159. Filed separately because it blocks every PR and is unrelated to any of them.

[kjgbot]

Narrowed: the hang is in main, and there are exactly two unbounded waits

It is not any PR's code

#159 changes one file, .github/workflows/cloud-runtime-artifact.yml, and nothing else:

$ git diff --name-only origin/main origin/ci/analyzer-skip-0904
.github/workflows/cloud-runtime-artifact.yml

Its kernel tree is byte-identical to main. It has now been hanging in Test kernel for 26+ minutes. So the hang is in main itself, reachable by any PR — it is not #139's gate work and not #158's retry change. That closes out both of my earlier wrong attributions.

wait_until is bounded, so it is not the culprit

crash_resume/support.rs:124:

pub fn wait_until(what: &str, mut condition: impl FnMut() -> bool) {
    let deadline = Instant::now() + Duration::from_secs(15);
    while !condition() {
        assert!(Instant::now() < deadline, "timed out waiting for {what}");

15 seconds, then it panics. A stalled journal condition would give a fast red with a clear message, which is not what we see.

The two waits that are unbounded

1. kill_process_group → child.wait() (support.rs:132)

pub fn kill_process_group(child: &mut Child) {
    kill_group(child.id());
    let status = child.wait().unwrap();

kill_group does kill(-pid, SIGKILL) on the group. If the child is not reaped — it is spawned .process_group(0), so this depends on process-group semantics holding exactly as expected — child.wait() blocks forever.

2. resume.wait_with_output() (agent.rs:134)

let resume = spawn_resume(&fixture, &run_id);
let dispatch = worker.event("step.dispatch").unwrap();
...
let output = resume.wait_with_output().unwrap();

If the resumed run never reaches a terminal state — a dispatch that never arrives, a lease never released — this never returns.

Relevant detail: the child is asleep for 300 seconds when it is killed

--pause-before-step lands in engine/drive.rs:

if !pause_consumed && options.pause_before_step.as_deref() == Some(step_id) {
    pause_consumed = true;
    thread::sleep(Duration::from_secs(300));
}

So the process being SIGKILLed is mid-sleep(300), and the test body runs that whole sequence twice (before-first, between-first-agent). That is the state the kill has to interrupt cleanly, every time.

I am deliberately not naming which of the two waits it is. I have guessed wrong three times on the related #155 and the cost each time was real; distinguishing these needs either a runner with a thread dump or a bounded reproduction, not more reading.

Concrete suggestion, unchanged and still root-cause-independent

Put a hard timeout on both waits. A test that fails in 60s with "resume did not exit" or "SIGKILLed child was not reaped" is diagnosable; a 30-minute cancellation with no output is not, and it currently costs the SDK suite entirely because cancellation skips every later step.

[kjgbot]

Reproduced locally, and the blocking wait is neither of the two I named

Both of my earlier candidates (child.wait(), resume.wait_with_output()) are wrong. Here is the actual state, captured from a live hung process.

Reproduction — no more 30-minute CI round trips

macOS cannot reproduce this. A Linux container can, but only running the whole binary; the test alone passes every time.

colima start --cpu 4 --memory 6
docker run --rm -v "$PWD":/src -w /src/kernel rust:1-slim-bookworm sh -c \
  'cargo test --no-run -p relayflowd --test crash_resume && \
   target/debug/deps/crash_resume-*'

Single test, Linux: 3/3 PASS in 0s. Full binary, Linux: hangs, still running at 10+ minutes against 47s on macOS.

That the test passes alone but hangs in the full binary is itself the finding: it depends on state left behind by earlier tests in the same process.

What is actually blocked

pid=528 (crash_resume)  main thread  wchan=futex_wait_queue
  └─ tid=595                         wchan=unix_stream_data_wait   ← the real block
pid=603 ppid=528  relayflowd --data-dir /tmp/.tmprxJwfJ serve   wchan=__skb_wait_for_more_packets
pid=94  ppid=1    relayflowd --data-dir /tmp/.tmpN14qfH serve   wchan=__skb_wait_for_more_packets

Two things:

1. A leaked daemon. pid=94 has ppid=1 — reparented to init. A relayflowd serve from an earlier test in this binary outlived its parent without being reaped, and its data dir /tmp/.tmpN14qfH is still on disk alongside the current test's /tmp/.tmprxJwfJ. So ServerGuard's cleanup did not run, or its kill missed.

2. A socket read that can never return. The hang is unix_stream_data_wait — a blocking read on a unix socket, in the worker event path (worker.event("step.dispatch")), with no timeout. The file descriptors say why it can never wake:

test pid 528:  fd 7 -> socket:[16469]
               fd 8 -> socket:[16469]     ← both ends held by the test itself
daemon 603:    fd 3 -> socket:[16460], fd 4/5 -> socket:[16468]
daemon 94:     fd 3 -> socket:[15721]

Inode 16469 is held twice by the test process and by neither daemon. With no other peer holding the write end, no data will ever arrive — and because the test still holds the far end itself, the read does not even get an EOF. It blocks forever rather than failing.

So the sequence is: an earlier test leaks a daemon, the fixture state that leak leaves behind causes the worker's socket to be wired to a peer that will never write, and worker.event(...) waits on it with no deadline.

What I would fix, in order

1. The leak. pid=94, ppid=1 should not exist. Whatever owns that daemon must reap it — that is the defect the rest follows from.
2. The unbounded read. worker.event(...) should take a deadline, so a missing dispatch is a fast, named failure instead of a permanent block. This is the "bound the wait" suggestion from before, now aimed at the right wait.

I am not proposing a patch yet — @khaliqgant asked for root cause first, and the leak is the part that deserves an owner's judgment about lifetime, not a quick timeout from me.

Correction

I previously listed child.wait() and resume.wait_with_output() as the two unbounded waits and said one of them was it. Neither is. I found them by reading; this was found by looking at a hung process, which is what I should have done one step earlier given I had already been wrong three times on the related #155.

[kjgbot]

Repro confirmed cleanly, with the identical signature to CI:

full run 1: rc=124 after 399s
test agent::rung_c_sigkill_boundaries_resume_only_unfinished_steps_via_real_cli
  has been running for over 60 seconds

rc=124 is timeout(1) firing at my 400s bound. Same test, same message CI prints before it burns the 30-minute budget.

So this is now reproducible in ~7 minutes on a laptop instead of a 30-minute CI cycle with no diagnostics, and a hung process can be inspected live — which is how the ppid=1 leaked daemon and the doubly-held socket inode above were found.

Worth knowing for whoever picks this up: run the whole crash_resume binary, not the single test. Alone it passes 3/3 in 0s.

[kjgbot]

It requires parallel execution — and serialising costs ~1 second

Decisive experiment, same Linux container, same commit (f1314b1), same binary:

SEQUENTIAL (--test-threads=1):
  PASS in 39s
  test result: ok. 34 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out

versus the default parallel run, which hangs and gets killed at my 400s bound:

full run 1: rc=124 after 399s
test agent::rung_c_sigkill_boundaries_resume_only_unfinished_steps_via_real_cli
  has been running for over 60 seconds

So the hang is not "Linux" and not that test in isolation — it needs tests running concurrently in the same process. That fits the two artefacts captured from the live hang: a relayflowd serve from an earlier test reparented to init (ppid=1), and a socket whose inode was held twice by the test process and by neither daemon, so the read could never return or even see EOF.

The cost of serialising is approximately nothing

A healthy parallel run of this binary is 38s. Sequential is 39s. These tests spend their time waiting on spawned daemons and sockets, not on CPU, so there is no parallelism to lose.

Compare that to the status quo: roughly half of runs burn the full 30-minute job budget and are cancelled, and cancellation skips Install SDK dependencies and every step after it — so the SDK suite does not run at all on those. A PR looks checked when two thirds of the gate never executed.

Suggested immediate mitigation, explicitly not a fix

Add --test-threads=1 to the kernel step. It runs the identical 34 tests and hides nothing; it only removes the concurrency the defect needs. One second of wall clock buys a deterministic gate.

The underlying defect stays open here and still wants fixing — the daemon leak in particular is real regardless of how the suite is scheduled, and a test double outliving its test is the kind of thing that eventually bites outside the harness.

I am not opening that PR unilaterally: @khaliqgant asked me to chase the root cause rather than patch around it, and serialising is exactly patching around it. Say the word and it is a one-line change.

[kjgbot]

Cost tally: this has now burned six CI cycles

Another one just now — #140's PR check, Test kernel running from 19:08, cancelled at 30 minutes. Second time on that PR alone.

PR	cycles lost to the hang
#139	1
#158	1
#159	1
#140	2
(this issue's original find)	1

Six cancellations × 30 minutes = three hours of CI wall-clock, and each one also skips Install SDK dependencies and everything after it — so on those runs the SDK suite never executed at all. A PR can sit "checked" with two thirds of the gate unrun.

The measured mitigation is still one line and effectively free:

--test-threads=1  ->  PASS in 39s, 34 passed 0 failed
default parallel  ->  hangs, killed at my 400s bound
healthy parallel  ->  38s

One second of wall clock, same 34 tests, nothing hidden. It does not fix the daemon leak — the ppid=1 orphan and the doubly-held socket are still real and still want fixing — it just stops the leak from eating a 30-minute budget on half of all runs.

@khaliqgant asked for root cause over patching around it, which is why I have not opened that PR. Recording the running cost so the tradeoff is visible rather than implicit: the root fix is in the session layer and wants an owner, while the serialisation is available now.