ref:main

fix(runner): never run a step outside its declared image in silence #55

merged colechristensen cole.christensen@gmail.com wants to merge fix/loud-execution-environment into main

Runner half of fangorn/anvil#374. The server half (why a job arrived with image: null at all) is a separate PR on fangorn/anvil.

The failure

A compile job ran on the runner host against the host’s Elixir 1.17.3 and died on mix.exs’s ~> 1.20.2, while the pipeline declares hexpm/elixir:1.20.2-erlang-29.0.3-debian-trixie-20260713. The whole job log was:

** (Mix) You're trying to run :anvil on Elixir v1.17.3 but it has declared in its
mix.exs file it supports only Elixir ~> 1.20.2

Not one line said where it ran. execute_bare announced itself with eprintln! — the runner’s own stderr, which nobody reading a failed job in the UI can see — so a step that ran outside its image was indistinguishable from one that ran inside it. Diagnosing this took an hour and started in the wrong place (the Elixir version) because the log gave nothing else to go on.

Changes

Every job logs its execution environment, to the job log, before the command runs.

Running in container image: hexpm/elixir:1.20.2-erlang-29.0.3-debian-trixie-20260713
Running in prepared image: anvil-prepared:9f2c1a04b7de
Running directly on the runner host (linux/x86_64) — no container image is
declared for this step, so it runs against whatever toolchain the runner has

The host line names the platform: the runner cannot tell “the step declared image: bare” from “the server sent no image”, so it states what it actually did and where.

A declared image that cannot be obtained fails the step, naming the image and docker’s reason. ensure_image_available pulls, and on failure falls back to a local copy if one exists (air-gapped runner, locally built tag, registry blip). With no local copy there is no correct environment left, so the job fails:

Cannot run this step in its declared image ghcr.io/foo/bar:1: <docker's stderr>

The previous code logged Warning: docker pull failed: … and continued into docker run, which then failed with a raw daemon error. It never ran on the host — but it never named the cause either.

prepare gets the same treatment for its base image. A sibling job on this same host reported Prepare failed: Prepare commands failed with exit code 1 when the docker daemon was simply unreachable; the prepare commands had never run. It now fails with cannot obtain base image <image>: <reason>.

Using cached prepared image: <tag> now names the base it was built from — the tag alone is a hash.

Tests

src/runner/executor.rs (wiremock log server, asserting on the lines the server actually received):

  • host_execution_is_announced_in_the_job_log — REQ-RUN-001
  • container_execution_names_the_image_in_the_job_log — REQ-RUN-001
  • unobtainable_image_fails_and_never_runs_on_the_host — REQ-RUN-002. Runs echo ran > ran-on-host with an unobtainable image and asserts the marker file does not exist: proof the command did not run on the host.

src/runner/prepare.rs:

  • missing_base_image_fails_naming_image_and_reason — REQ-RUN-002, and asserts the message is not “Prepare commands failed”, which was the misleading one.

All deterministic with or without a docker daemon (the test image uses the .invalid TLD, and a missing docker binary fails the same way) — the CI image has no docker.

cargo test 196 + 249 passed, 0 failed
cargo clippy --all-targets -- -D warnings clean
cargo fmt -- --check clean

Not fixed here

The runner still cannot distinguish “no image declared” from “the server failed to send one” — the wire contract has one nullable image field. Making that explicit needs a server-side field and is not worth it while the server half of #374 removes the way a job got a wrong image: null in the first place.

restore_from (fangorn/anvil#312) is sent by the server in the claim payload and the runner has no handling for it at all. Untouched here.


Proof the tests fail before the fix

Checked out origin/main, applied only the new tests, and reverted the production changes in place (describe_exec_env left defined so the pure unit test still compiles; its call site removed, and both warn-and-continue pull blocks restored verbatim). cargo test --lib:

test runner::executor::exec_env_tests::host_execution_is_announced_in_the_job_log ... FAILED
test runner::executor::exec_env_tests::unobtainable_image_fails_and_never_runs_on_the_host ... FAILED
test runner::prepare::tests::missing_base_image_fails_naming_image_and_reason ... FAILED
test result: FAILED. 193 passed; 3 failed

with these assertions:

no line announced host execution; got []
a step whose declared image is unavailable must fail:
ExecResult { exit_code: 1, end_reason: Finished }
the failure must name the base image;
got "Prepare commands failed with exit code 1"

The first is the incident: a job ran on the host and its log said [] about it. The third is the sibling deps job’s real failure text, which blamed the prepare commands for an unreachable daemon.

On this branch all lib tests + integration tests pass (cargo test: 198 lib + 249 integration, 0 failures), along with cargo fmt --check and cargo clippy --all-targets --all-features -- -D warnings.

One test passes before and after, deliberately: container_execution_names_the_image_in_the_job_log. The old code did log Pulling image: <image>, so a containerized step was already identifiable. It is a regression guard, not a reproduction — recorded here so the “fails before” claim isn’t overstated.

unobtainable_image_fails_and_never_runs_on_the_host deserves the same precision. Its marker-file assertion (echo ran > ran-on-host, then assert the file does not exist) passed pre-fix too — there was no silent host fallback in the runner’s docker path; a failed pull fell into docker run, which failed. What did not exist was the loud failure: pre-fix the job returned Ok(exit_code: 1), indistinguishable from “the test suite failed”. The marker assertion pins that no such fallback is ever introduced; the expect_err pins the new behaviour.

A second silence, in the same file tree: a failed checkout

Review of fangorn/anvil#239 flagged the sibling of this bug one module over, in workspace.rs. prepare runs git checkout --force <commit_sha> to decide the tree the job compiles. If that had gone through the warn-and-continue helper, a bad SHA would return Ok(()) — and because there is deliberately no git clean (the workspace is reused to keep build caches warm), the directory does not end up empty. It keeps the previous job’s fully-built tree. The job then compiles and tests yesterday’s code, passes, and reports green in the correct container, with nothing in its log naming the commit it was supposed to build. loop_runner.rs only logs on Err, which never arrived.

That is the same class this PR exists to remove — a step that ran against something other than what it declared, with no line saying so — so it belongs here.

The Ok-swallowing itself was already fixed on main by #53, which routed the clone and the checkout through run_git_checked. Reporting that accurately: the review was written against the pre-#53 file. What was genuinely missing is what makes it a regression rather than a passing detail — nothing tested it. This PR adds that test, plus the SHA in the error message.

Reverting run_git_checked to the lenient helper, the new test fails with the bug’s own signature:

warning: git checkout failed: fatal: unable to read tree (1234567890abcdef1234567890abcdef12345678)
panicked at src/runner/workspace.rs:767:
a commit that cannot be checked out must fail the job:
"/var/folders/.../anvil-work-68208/.../a28bf26b-1"

prepare handing back a workspace path, with the first job’s tree still in it — the test asserts that tree is still on disk precisely to show what the job would have built.

The error now names the SHA as well as the operation (git checkout <sha> failed: …). Git’s own stderr usually mentions it, but the one operation whose silent failure substitutes a different commit should not depend on that.

The blind spot

The runner’s execution path had no test that ran execute() at all. Everything under src/runner/ that was tested was pure: tag computation, prune policy, workspace paths, EndReason mapping. The container-vs-host branch — four lines, and the single most consequential decision the runner makes — was reachable only by running a real job on a real host with a real daemon.

That has a specific consequence: the unavailable-Docker branch had never been executed by anything. Not in CI (the rust:1.95-trixie image has no docker), not locally (developers have a daemon). So warn-and-continue-into-docker run looked fine on inspection and had never been observed. The new tests run in both environments precisely because every way of not having an image — no docker binary, no daemon, no such image — converges on the same assertion.

The same shape as fangorn/ex_git_objectstore#78, found today: its one thin-pack test injects a stub resolver, so the real resolver has zero coverage. Both are a seam mocked on the side that is broken.

Prior art

fangorn/anvil-cli#42 (inspect/prune/force-rebuild prepared images) is adjacent and not a duplicate — commented there with the relationship. Short version: this job never entered the prepared-image path at all, so no image was stale or missing; #42’s asks are unaffected except that Using cached prepared image: <tag> (built from <base>) now supplies, for the image a job used, the base-image back-reference #42 notes the tag lacks.

Created Jul 30, 2026 at 18:07 UTC | Merged Jul 31, 2026 at 05:14 UTC by colechristensen cole.christensen@gmail.com