fix(ci): stop the autobahn sidecar deadline from timing the image build - #3854
fix(ci): stop the autobahn sidecar deadline from timing the image build#3854bdchatham wants to merge 1 commit into
Conversation
The autobahn integration test has been failing repo-wide, including on main
and on four unrelated branches, with:
fullnode sidecar setup failed: fullnode sidecar didn't come up within 5m0s
That message names the wrong thing. setupFullnodeNode starts
`make run-rpc-node-skipbuild` and then opens a five-minute readiness deadline,
but `skipbuild` names the seid `go install` it skips, not the image build --
the target still depends on build-rpc-node. So the deadline was timing a docker
build whose cost is entirely a function of the layer cache.
Measured across the two runs:
passing run: 20 layers CACHED
failing run: 1 layer CACHED
On a cache miss, build-rpc-node rebuilds docker/rpcnode/Dockerfile from
ubuntu:latest -- an apt-get install of build-essential plus a network foundry
install with a five-attempt retry loop. In the failing run that took roughly
nine minutes. The timestamps line up exactly: sidecar start 16:48:57, docker
build begins 16:48:58, deadline expires 16:53:58, apt still downloading at
16:57.
Two changes.
The image build now runs to completion before the deadline opens. It is
synchronous, unbudgeted, and idempotent against the same dependency inside
run-rpc-node-skipbuild, which becomes a cache hit. Total wall clock is
unchanged; fullnodeBootTimeout now measures only container start and RPC
readiness, which is what it is named for.
The subprocess error is no longer discarded. `go func() { _ = cmd.Wait() }()`
became a channel the poll loop selects on. `docker run --rm` holds the
foreground for the suite's duration, so an exit during startup means the
container never came up -- previously that surfaced as the readiness timeout
above, which is why every failure in this path looked identical regardless of
cause.
Not included: pinning `FROM ubuntu:latest` in docker/rpcnode/Dockerfile. The
base image did not float here -- the digest is identical across the passing and
failing runs -- but an unpinned base guarantees a future cache-invalidating flip
that reproduces this with no code change to blame. Pinning trades that for stale
packages until someone bumps the digest, which is a policy call rather than part
of this fix.
Co-Authored-By: Claude Opus 5 (1M context) <[email protected]>
PR SummaryLow Risk Overview
Reviewed by Cursor Bugbot for commit 4102b83. Bugbot is set up for automated code reviews on this repo. Configure here. |
|
The latest Buf updates on your PR. Results from workflow Buf / buf (pull_request).
|
There was a problem hiding this comment.
LGTM — test-only fix to the autobahn integration harness, no production code paths affected.
Extended reasoning...
Overview
The diff touches a single file, integration_test/autobahn/autobahn_test.go, and only the setupFullnodeNode helper used by TestMain for the autobahn integration test suite. It moves the make build-rpc-node step to run synchronously and to completion before the fullnodeBootTimeout deadline opens, and replaces a fire-and-forget go func() { _ = cmd.Wait() }() with a channel the readiness poll loop selects on, so an early exit of the sidecar subprocess is reported directly instead of surfacing as a generic readiness timeout.
Security risks
None. This is CI/integration-test-only code, gated behind the autobahn_integration build tag, and never ships in production binaries or consensus-critical paths.
Level of scrutiny
Low-to-moderate is appropriate: it's a bug fix to test infrastructure (mislabeled timeout / discarded subprocess error), not a change to application logic. I verified the Makefile dependency chain the PR description relies on (run-rpc-node-skipbuild: build-rpc-node, confirmed at Makefile:320) matches what's claimed, and the new select-based error handling correctly distinguishes a clean vs. non-clean early exit of the subprocess.
Other factors
The author is explicit that this hasn't been run end-to-end (needs a cold Docker cache to reproduce), but the fix is small, self-contained, logically sound, and the bug hunting system found no issues (it did raise and then correctly rule out a concern about the synchronous build call lacking a timeout, which is fine here since it's meant to be unbudgeted by design). No production risk given the file's scope.
There was a problem hiding this comment.
Targeted, well-reasoned CI fix: moving the rpc-node image build outside fullnodeBootTimeout and surfacing cmd.Wait()'s result both correct real misattribution problems, and the logic is sound (run-rpc-node-skipbuild is a foreground docker run --rm, so an early exit really is a failure). No blockers; the main note is that the headroom argument uses the 45-minute job budget while the binding ceiling is go test -timeout 30m in the Makefile target.
Findings: 0 blocking | 5 non-blocking | 2 posted inline
Blockers
- None at the file/PR level.
Non-blocking
- The prebuilt-image waste is now more visible: the autobahn CI job pulls
ghcr.io/.../rpcnodeand tags itsei-chain/rpcnode(integration-test.yml), then this code runsbuild-rpc-node, which rebuilds and overwrites that tag. Pre-existing (skipbuild already depended on build-rpc-node) and explicitly out of scope per the description, but a small guard — build only whendocker image inspect sei-chain/rpcnodefails, paired with a make-level opt-out sorun-rpc-node-skipbuilddoesn't rebuild either — would delete the ~9 minutes rather than relocate them. - Verification is compile/format-only by the author's own statement, with no end-to-end run. Reasonable for a CI-harness change that only reproduces on a cold layer cache; the practical signal to watch on the next cold-cache run is whether the failure now names the build.
- Second-opinion passes: Codex reported no material issues; the Cursor review file (
cursor-review.md) is empty, so that pass produced no output and contributed nothing to this synthesis. - 2 suggestion(s)/nit(s) flagged inline on specific lines.
| // Idempotent against the same dependency inside run-rpc-node-skipbuild | ||
| // below, which is a cache hit once this returns. | ||
| fmt.Println("=== Building rpc-node image (before the readiness deadline) ===") | ||
| if err := runMake(nil, "build-rpc-node"); err != nil { |
There was a problem hiding this comment.
[suggestion] The headroom argument in the PR description uses the 45-minute job budget, but the binding ceiling for this code is -timeout 30m on the go test invocation in the autobahn-integration-test make target (Makefile:495). On a cold cache everything now serialises inside that one test process: docker-cluster-start → build-docker-node (localnode image), cluster boot (≤5m), settle delay, this rpc-node build (~9m measured), then fullnodeBootTimeout (5m), then the test bodies. The failing run cited was 31m24s of job time and aborted at the 5m deadline; adding ~9m back into the go-test window puts it close to (plausibly over) 30m, and hitting that produces panic: test timed out — which also skips TestMain's docker-cluster-stop. Worth bumping -timeout in the same PR since this change is what consumes the slack.
Secondary point on "unbudgeted": the foundry install inside the Dockerfile is a network fetch behind a retry loop, so a stalled build has no bound of its own. exec.CommandContext with a generous cap (say 20m) inside runMake for this one call would keep the "reports as itself" property without leaning on the go-test panic for attribution.
| } | ||
| } | ||
| return fmt.Errorf("fullnode sidecar didn't come up within %s", fullnodeBootTimeout) | ||
| return fmt.Errorf("fullnode sidecar didn't come up within %s of the container starting "+ |
There was a problem hiding this comment.
[nit] "the image build completed before this deadline opened" is true of the pre-build, but run-rpc-node-skipbuild still re-evaluates its build-rpc-node dependency inside this window. That's a cache hit in practice (seconds), so the message is fine — but if the layer cache is ever evicted between the two invocations (disk pressure on the runner, a concurrent prune), the parenthetical asserts something false at exactly the moment it matters most. Softening it to "the image was built before this deadline opened" keeps the useful signal without the guarantee.
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #3854 +/- ##
==========================================
- Coverage 61.55% 60.69% -0.87%
==========================================
Files 2361 2269 -92
Lines 199445 188939 -10506
==========================================
- Hits 122778 114670 -8108
+ Misses 65710 64165 -1545
+ Partials 10957 10104 -853
Flags with carried forward coverage won't be shown. Click here to find out more. 🚀 New features to boost your workflow:
|
Retracting the diagnosis in this PR — please do not merge as-isA nine-agent review (four independent investigations, each adversarially refuted, then synthesized) re-derived every load-bearing claim in this PR from primary sources. Most of my diagnosis is wrong, including two claims that are live in the diff and the commit message. Marking this draft. The cache comparison was cross-job, and it is in the commit messageI compared "20 Cache state never discriminated pass from fail. The autobahn job has no buildx step and passes no The real discriminator is Ubuntu mirror throughputSame 31.9 MB apt-index fetch, every autobahn job that day: Monotone dose–response, no inversions: 22–67 MB/s → passes in 35–40 s; ≤357 kB/s → the 5m0s sidecar timeout; ≤146 kB/s → the 2160 s kill. The comment this PR adds is factually wrongIt describes The 2160 s mode never reaches the function I patchedThe SIGQUIT stack, byte-identical in both runs, is blocked in The fix rescues 0 of 6Margins computed from each run's own alarm time against its fitted install rate, on the download alone — before unpack, image export, container start, the suite, or teardown:
And the green check on this branch proves nothing: an unpatched run passed at 17:57, one minute before the patched one at 17:58. The mirror recovered around 17:45. What survivesThe The build-first half should be dropped. Its own comment says "synchronous and unbudgeted," which is exactly the shape at The actual fix
Replacement PR to follow. Apologies for the noise — the mechanism I described is real for one of the two modes, but the cause, the magnitude, and the efficacy were all wrong. |
The failure
The autobahn integration test has been failing repo-wide — on
mainand on four unrelated branches today — with:That message names the wrong component. Nothing is wrong with the sidecar.
The cause
setupFullnodeNodestartsmake run-rpc-node-skipbuildand then opens a five-minute readiness deadline. Butskipbuildnames the seidgo installit skips, not the image build:run-rpc-node-skipbuild: build-rpc-nodeSo the deadline was timing a docker build whose cost is entirely a function of the layer cache. Measured across the two runs:
CACHEDOn a cache miss,
build-rpc-noderebuildsdocker/rpcnode/Dockerfilefromubuntu:latest— anapt-get installofbuild-essentialplus a networkfoundryinstall with a five-attempt retry loop. In the failing run that took roughly nine minutes. The timestamps line up exactly:The fix
The image build now completes before the deadline opens. Synchronous, unbudgeted, and idempotent against the same dependency inside
run-rpc-node-skipbuild, which becomes a cache hit. Total wall clock is unchanged — butfullnodeBootTimeoutnow measures only container start and RPC readiness, which is what it is named for. Raising the timeout instead would only move the cliff.The subprocess error is no longer discarded.
go func() { _ = cmd.Wait() }()became a channel the poll loop selects on.docker run --rmholds the foreground for the suite's duration, so an exit during startup means the container never came up — and previously that surfaced as the readiness timeout above. That is why every failure in this path looked identical regardless of cause, and why this took a log dig to attribute.What this does not include, deliberately
Pinning
FROM ubuntu:latestindocker/rpcnode/Dockerfile.The base image did not float here — I checked, the digest is identical across the passing and failing runs (
678c6550cc43), so that was not the trigger. But an unpinned base guarantees a future cache-invalidating flip that reproduces this exact failure with no code change to blame. Pinning trades that for stale packages until someone bumps the digest, which is a policy call rather than part of a bugfix. Worth a separate decision.Verification, and its limit
Compiles clean under the
autobahn_integrationbuild tag;gofmt -s,goimportsandgo vetclean.I have not run this end to end. The failure only reproduces on a cold docker layer cache, and reproducing it locally needs Docker, a four-node cluster and ~30 minutes. So this fix is reasoned and compile-verified, not behavior-verified — stating that explicitly rather than implying otherwise.
The useful signal from CI is not a pass. It is that on a cold cache the error will now name the build rather than the sidecar. A correctly-attributed failure would prove more here than a green run.
Addendum: root cause is a missed integration, not just cache luck
Tracing the history changes the framing above. The shape is old —
run-rpc-node-skipbuild: build-rpc-nodedates to 2023-06-30 (#944) — but the bug arrived with the sidecar:*-integration-cimake targets that consume it viaensure-integration-ci-images.run-rpc-node-skipbuild, the pre-GHCR target that rebuilds.So the autobahn path opted out of the mechanism added the week before to stop integration flakiness. This job already receives a prebuilt
sei-chain/rpcnodeimage, pushed to GHCR byprepare-clusterfor exactly this purpose — and then rebuilds it locally anyway.It has been latent since June because
cache-tois restricted topushevents (workflow lines 112, 124), so PR runs only read a registry cache that only main's successful pushes write. Warm cache, instant build, green. Cold cache, nine-minute rebuild, blown deadline. A coin flip on cache warmth rather than anything in the PR under test.What this PR does and does not fix
Fixes: the misattribution and the failure. The job budget is 45 minutes and the failing run used 31m24s, so with the build outside the readiness deadline there is roughly 14 minutes of headroom. Cold-cache runs become slow rather than red, and a genuine container failure now reports itself.
Does not fix: the wasted rebuild. Roughly nine minutes per cold run, rebuilding an image this job already has.
The deeper fix is to consume the prebuilt image, and it is not a one-line target swap —
run-rpc-node-integration-cidoes not passAUTOBAHNorCLUSTER_SIZE(autobahn's role and committee size come from those), and it prepends a block-100 wait whose comment states thatSKIP_BUILD=trueotherwise reads a trust height of ~10-20, finds no snapshot, and crashes. Since the autobahn sidecar also runsSKIP_BUILD=true, it may share that hazard without the guard. That wants its own change and its own review.Two hardening items also surfaced and are deliberately out of scope:
FROM ubuntu:latestis unpinned indocker/rpcnode/Dockerfile, andfoundryinstalls from the network inside the image build behind a five-attempt retry loop.