The download that contaminated the benchmark

2026-10-10 · 10 min read

Contents

$ git show --name-status --relative --format='%h %ad %s' --date=format:'%H:%M' dfd9f06 -- a9-results
dfd9f06 01:59 a9-results: gpt-oss long-ctx run overlapped downloads, marked contaminated; rerun queued

R100	a9-results/longctx-gptoss120b-b11538.jsonl	a9-results/longctx-gptoss120b-b11538.contaminated-by-download.jsonl

That rename is a confession. The file holds gpt-oss-120b's long-context sweep on the A9 Mega: llama-bench prefill and generation speed at depth 0, 32k, 64k and 96k tokens. It started at 01:18. The model downloads started at 01:19.

R100 means the content didn't change by a byte. The numbers stayed exactly as they were, and the filename now says they can't be trusted. The commit subject says the rest: rerun queued. There was no queue running yet. The runner's first commit had landed 25 seconds before the rename; the service started 94 seconds after it.

How much a download bent the numbers#

The rerun, job 51, landed at 04:02 with nothing else on the box. Same build (llama.cpp b11538, 79e2e74eb), same flash attention, same f16 KV cache. So the size of the contamination is a measurement now, not a guess.

Prefill only, pp512 in tokens per second:

Depth	Contaminated	Clean (job 51)	Contaminated vs clean
0	1197.79	1186.51	+1.0 %
32k	334.11	383.57	−12.9 %
64k	141.37	139.67	+1.2 %

Generation doesn't get a row. The contaminated run measured 64 generated tokens per test and the clean one 128, so tg64 against tg128 is two different questions. The contaminated run's 96k depth has no clean twin either; job 51 went to 130048 instead.

Not ruined. One row bent. The 32k prefill row started at 01:18:25 and the next test at 01:19:22, so it straddles the minute the downloads began. The 64k row ran from 01:19:24 to 01:23:00, inside the download window by the plan's own note, and came out 1.2 % faster than clean. I don't know why one row took the hit and the next didn't. Every row in both files is a single sample, and one sample per row doesn't support a theory. It does support "don't publish the 32k number". It's also why a single run of a benchmark cell gets less trust here than it used to.

The downloads weren't polite, either. The fetcher drives aria2c with several connections per file, because its own comment says Hugging Face's CDN caps a single stream around 10–15 MB/s. Together they pull about 107 MB/s, most of a gigabit link, and no file counts as done until a full sha256 pass matches the repo's LFS hash. On an APU, all of that traffic lands in the same memory the GPU is prefilling from.

A queue with lanes that never overlap#

The fix was a rule, then a runner to enforce it. runner.py is about 200 lines of Python under a systemd unit, a9-jobs. Jobs are bash files in ~/jobs/queue/, each with a lane, a DONE_IF test and a retry count in its header. From its docstring:

Jobs must be idempotent: write results to *.tmp and rename on success, so a power cut can only
leave a temp file and the job simply reruns.

Crash recovery: on start, everything in running/ goes back to queue/ (a reboot killed it).
GPU lane: also waits while a foreign GPU user runs (llama-server, llama-bench, flm) that this runner
did not start, so manual work and the queue don't collide.
Exclusive lanes (user rule 2026-10-10): net (downloads) and gpu (tests) never run at the same time, so
a download's network/disk/sha256 load can't skew a benchmark. Pending downloads go first; a test also
needs its files present and verified, which its REQUIRES line checks.

Power cuts happen here. Hence a queue that survives a reboot.

The one line that matters most decides when a job is finished:

verified = check(meta["DONE_IF"])
if rc == 0 and verified is not False:

An exit code alone doesn't finish a job. The job's DONE_IF has to agree, and for a download that means the sha256 matched. Anything else goes back to the queue until its retry budget runs out: three attempts by default. I've been burned by a loop that reported done after one branch of forty hours before. This is the scar tissue.

The first reboot test: systemd deleted the queue#

The service started at 02:00:46. At 02:02:53 I rebooted it on purpose, mid-download, to watch the recovery. There was nothing to watch. The box came back and the queue didn't. The journal of that boot had the reason:

Oct 10 02:03:13 a9-mega systemd[1]: multi-user.target: Found ordering cycle: a9-jobs.service/start after a9-telemetry.service/start after multi-user.target/start - after a9-jobs.service
Oct 10 02:03:13 a9-mega systemd[1]: multi-user.target: Job a9-jobs.service/start deleted to break ordering cycle starting with multi-user.target/start

Nothing failed, because nothing ran. systemd quietly deleted the start job and left a note explaining that it had done so. The ordering lines, as first committed:

After=multi-user.target
WantedBy=multi-user.target

That's the telemetry unit. And the queue:

Wants=network-online.target
After=network-online.target a9-telemetry.service
WantedBy=multi-user.target

The third edge is invisible. WantedBy=multi-user.target makes the target want the unit, and the systemd.target man page says a target "will automatically complement all configured dependencies of type Wants= or Requires= with dependencies of type After=". So multi-user.target orders itself after the queue. The queue waits for telemetry, telemetry waits for multi-user.target. Circle.

Which raises the obvious question: telemetry had After=multi-user.target and WantedBy=multi-user.target on its own, and it had come up fine at boot at 01:08. Why no cycle then? Because systemd checks for exactly that case. In unit_add_default_target_dependency(), the implicit edge is skipped when the reverse edge already exists:

/* Don't create loops */
if (unit_has_dependency(target, UNIT_ATOM_BEFORE, u))
        return 0;

unit_has_dependency() looks at direct edges. A two-unit loop gets defused; a three-unit loop sails through to the transaction, where systemd breaks it by throwing out a job. It picked the queue.

The fix, fix-15, drops After=multi-user.target from telemetry and the telemetry ordering from the queue. Neither needed it. A second deliberate reboot at 02:04:54 and both services were back by 02:05:23, along with this:

{"ts": "2026-10-10 02:04:54", "job": "12-net-dsv4flash.job", "event": "stopped", "note": "runner shutting down; job goes back to queue at next start"}
{"ts": "2026-10-10 02:05:23", "job": "12-net-dsv4flash.job", "event": "recovered", "note": "was running at start (reboot/crash)"}
{"ts": "2026-10-10 02:05:23", "job": "-", "event": "runner-start"}
{"ts": "2026-10-10 02:05:23", "job": "12-net-dsv4flash.job", "event": "start", "lane": "net", "pid": 1534, "attempt": 1}

Twelve downloads finished by 02:32:44, every one verified: true, about 400 GB of models in total. The first GPU job started that same second.

What the queue caught: a GPU ring reset at 04:19#

The first real failure wasn't a power cut. Job 52, Laguna-S-2.1, a long-context speed screen, at 04:19:11 (kernel log, filtered to the timeout and reset lines):

Oct 10 04:19:11 a9-mega kernel: amdgpu 0000:c6:00.0: ring comp_1.2.0 timeout, signaled seq=143829, emitted seq=143831
Oct 10 04:19:11 a9-mega kernel: amdgpu 0000:c6:00.0: Starting comp_1.2.0 ring reset
Oct 10 04:19:11 a9-mega kernel: amdgpu 0000:c6:00.0: reset compute queue (1:2:0)
Oct 10 04:19:11 a9-mega kernel: amdgpu 0000:c6:00.0: Ring comp_1.2.0 reset succeeded
Oct 10 04:19:11 a9-mega kernel: amdgpu 0000:c6:00.0: [drm] device wedged, but no recovery needed

"Device wedged, but no recovery needed" is a fine thing to read at four in the morning. The job exited with rc 134: 128 plus SIGABRT. Fourteen seconds later the queue had it running again, and when that one died too, again (its retry events):

{"ts": "2026-10-10 04:19:25", "job": "52-gpu-laguna.job", "event": "retry", "rc": 134, "attempt": 1, "verified": false}
{"ts": "2026-10-10 04:33:45", "job": "52-gpu-laguna.job", "event": "retry", "rc": 134, "attempt": 2, "verified": false}
{"ts": "2026-10-10 04:50:25", "job": "52-gpu-laguna.job", "event": "failed", "rc": 134, "attempt": 3, "verified": false}
{"ts": "2026-10-10 04:50:25", "job": "53-gpu-dsv4flash.job", "event": "start", "lane": "gpu", "pid": 14619, "attempt": 1}

Three attempts, a clean give-up, and the next job in the same second. Job 53 then ran for two hours and fourteen minutes and finished rc 0. Why the GPU timed out is a separate rake.

Everything that said "ok"#

The queue reads exit codes and DONE_IF. The rest of the tooling around it had other ways to report success.

An intake job that exited 0 and still failed. At 08:38:27 the queue logged a retry with rc 0 and verified false. The job's own gate had refused to grade a model, the script exited cleanly, and DONE_IF disagreed. The queue sided with DONE_IF. That one it got right.

A wait nobody logged. Then nothing happened for 2 hours 16 minutes. The GPU lane was politely waiting for a GPU process it hadn't started, as designed. It just never said so. The runner now writes a gpu-wait event naming the process.

A publish script that published nothing. After each GPU job, publish.sh commits the results and pushes. The line that staged them:

git add agent-playground/bench/a9-results agent-playground/bench/intake 2>/dev/null

intake/ didn't exist yet. git add with one missing path fails as a whole and stages nothing; the error went to /dev/null. The next line saw an empty index and exited 0. The fix's own comment puts the silence at six hours. It's the same family of bug as a wrapper that always exits 0: nothing lied on purpose, every layer reported its own small success.

A coding agent that wrote the wrong file and said so cheerfully. Before a model is graded, a smoke test asks each agent client to create hello.py containing print('hi'). From the intake log:

[2026-10-10 10:55:27] SMOKE gptoss-120b:
    HARNESS   RC   SECS   FILE   NOTE
    opencode  0    79     yes    ok
    pi        0    13     yes    ok
    claude    0    57     no     ok

Claude Code, driving gpt-oss-120b, exited 0 and printed "File hello.py created with the requested content." It had. The session transcript holds one tool call: a Write with an absolute path to ~/hello.py, in my home directory, while the session's working directory was the smoke test's own. Exit code: success. The client's message: success. The NOTE column: ok. Only FILE told the truth.

The gate passed anyway, and that's not a bug. Its rule, in the script's header, is to grade only if the opencode smoke wrote the file. It never claimed to watch claude.

The power cut at 11:30:17: the case it was built for#

At 11:30:17 the mains went. Laguna was back on the queue, rerunning with a longer GPU timeout, in the middle of its 128k row. The last telemetry rows, 11:30:10 to 11:30:16, show a box doing nothing dramatic: 44–51 W package power against a 132 W peak earlier in the same job, Tctl 54–55 °C, GPU 100 % busy, about 89 GiB of GTT (the GPU's share of system RAM) in use. The last thing the journal kept was systemd removing a user slice after an ssh logout.

The BIOS is set to power on when AC returns. The kernel's first line is stamped 11:31:38. Then:

{"ts": "2026-10-10 11:31:53", "job": "52-gpu-laguna.job", "event": "recovered", "note": "was running at start (reboot/crash)"}
{"ts": "2026-10-10 11:31:53", "job": "-", "event": "runner-start"}
{"ts": "2026-10-10 11:31:53", "job": "52-gpu-laguna.job", "event": "start", "lane": "gpu", "pid": 1550, "attempt": 1}

Ninety-six seconds from the journal's last line to the job running again. Nobody touched the box. Note attempt: 1: a power cut doesn't spend the retry budget, because the attempt counter only moves when a job finishes badly.

Then the less flattering part. The job reran, exactly as the docstring promised, from depth 0. The speed screen truncated its .tmp on start, so the 32k and 64k rows it had already finished went with it, including the first 64k row Laguna had ever completed. A second cut at 12:48:52, and the box didn't boot again until 16:38; the queue recovered the job at 16:39:11 and it threw away its rows again.

The queue guaranteed the job. Nobody had asked the job to remember how far it got. The speed screen now keeps its .tmp across restarts and skips depths that already have both rows.

A UPS is on order.

Filed under: amd, benchmarks, systemd, linux, local-llm

Sources#

systemd.target(5) — default dependencies: targets add After= to everything they Want=.
systemd src/core/unit.c — unit_add_default_target_dependency(), the direct-edge "Don't create loops" check.
systemd src/core/target.c — target_add_default_dependencies(), which calls it for every wanted unit.
llama.cpp — llama-bench, build b11538 (79e2e74eb), used for both sweeps.
aria2 — the multi-connection downloader behind the model fetches.