ci: offchain fork job timeouts are undiagnosable, and the loader races the build

[juan-malbeclabs]

Summary

The two offchain-local-validator fork jobs can fail with Solana fork did not start within 60 seconds, and when they do the logs contain nothing that identifies why. The loader's output is sent to /dev/null, so a loader that failed for its own reasons is indistinguishable from one that was merely slow. Separately, the way the loader is started makes it structurally likely to be slow on a cold cache.

Observed on PR #4341 in run 35029844666; both jobs passed on a re-run, so the failure is transient rather than deterministic.

The diagnostic gap

run: cargo run -p doublezero-solana-fork-cli --bin doublezero-solana-fork -- -um --reset ... > /dev/null 2>&1 &

Nothing the loader prints is retained. The only signal is the generic timeout from the wait loop, which cannot distinguish:

• the loader crashing or rejecting a flag,
• the loader failing to clone accounts from mainnet-beta,
• the loader still compiling when the window expired.

In the run above, the third is plausible on timing (below), and the second is plausible because sdk-compat-test failed in the same window with RPC 503 Service unavailable, which points at upstream mainnet RPC being degraded at 22:14–22:21 UTC. The logs cannot tell these apart, which is the primary problem: the job is unactionable when it fails.

The structural race

The loader is backgrounded as cargo run, then the next step runs a foreground cargo build:

- name: Start Solana mainnet-beta fork in background
  run: cargo run -p doublezero-solana-fork-cli --bin doublezero-solana-fork -- ... &
- name: Build `doublezero-solana`
  run: cargo build -p doublezero-solana-cli --bin doublezero-solana

Started that way the loader must compile before it can serve, and both cargo invocations contend for the same target/ lock, so the loader blocks behind the foreground build. The readiness wait then starts counting at the moment that build finishes. Timeline from the failing run:

Time (UTC)	Event
22:14:21	Swatinem/rust-cache reports No cache found.
22:14:40	Fork step launches cargo run … &
22:14:45	Build doublezero-solana starts compiling
22:19:19	Foreground build finishes (4m39s)
22:19:19	Readiness wait begins
22:21:20	Wait gives up

This leaves the loader ~2 minutes to finish compiling and boot. It is a real defect regardless of what caused this particular failure: the readiness budget is spent on compilation that could have happened earlier, and the margin shrinks exactly when the cache is cold.

Swatinem/rust-cache is keyed on Cargo.lock, so a PR changing Cargo.lock compiles the whole graph cold and has the least margin. That is also the only reason the workflow runs on such a PR: its path filter is offchain/**, solana/**, Cargo.lock, Cargo.toml, and Cargo.lock is often the sole match, with nothing under offchain/ touched.

Smaller problems

1. The timeout message is wrong. Both scripts loop for i in {1..60} with sleep 2, i.e. ~120s, but report did not start within 60 seconds. The observed 22:19:19 → 22:21:20 gap is 2m01s, matching the loop.
2. Nothing checks the loader is alive. If the backgrounded process dies immediately, the scripts still spin the full window before reporting a timeout.

Proposed fix

• Compile the loader in the build step and start it from target/debug/doublezero-solana-fork, removing both the lock contention and the compile inside the readiness window.
• Send the loader's output to a log file and dump it when readiness fails, so the next failure is diagnosable.
• Record the loader's pid and fail fast if it exits.
• Derive the timeout message from the actual window.

Affected files

• .github/workflows/offchain.local-validator.yml
• offchain/sh/test_doublezero_solana_fork.sh
• offchain/sh/test_validator_debt_fork.sh