The compile cache handed four jobs a crate file their dependents were not built against (E0463, E0460), 21:54-21:58Z 11-13 #63

New issue

Open

opened 2026-11-13 22:20:47 +00:00 by xemmerling · 0 comments

xemmerling commented

2026-11-13 22:20:47 +00:00

Owner

Production, 9faf6c61 (the build before your 22:08Z promote). The wrapper, slot and placement files named below are unchanged in 6ebaa239, so this stands for the build production runs now. Nothing was changed on production; no code of mine is in flight.

What happened. No job had ended this way in the 5 h 20 min since the 16:32Z restart. Then four people's jobs ended cache_unreachable within three minutes, 21:54:49 to 21:57:51Z 11-13:

j559-80704, cargo build -p tilo-web-desktop for wasm (started 21:49:32): E0463, can't find crate tilo_delivery_protocol (the .rmeta cargo handed it, 627071 bytes as the compile started and now).
j559-80090, test/ebook (21:40:48): E0463, runtime_collab (9820695 bytes, both times).
j559-80075, test/contacts (21:40:35): E0460, "found possibly newer version of crate tilo_dav which cloud_source_dav depends on".
j559-80080, test/notes (21:40:35): E0463, package_store (1032246 bytes, both times).

The last three are one session's checks, running together; the first is another person's. All were run again on the same node. All four passed (the last at 22:18:06Z). So the files were wrong for a moment, not for the inputs.

What else was true then. A wave of 86 people's jobs started within ten minutes. The node's free disk fell from 1,203 to 664 GiB and reached its floor at 22:05Z; the freer made one large pass at 21:52:32 to 21:53:20Z. Kept memory passed the offer in 21 of 120 samples of the half hour (highest 117%), and t_sched_grow_total rose from about 25 to 67 and then 125 per ten minutes. No job ended for memory.

What I read in the code (verified by me).

The refusal records only the SIZE of each handed file before and after (crates/t-cache/src/cargo/wrapper/run.rs, Handed::of and file). A file replaced by another of the same size, or emptied and rewritten, reads the same as an untouched one. That is why these four lines cannot tell us what happened.
After every run that returned, passing ones too, the wrapper asks Request::Again (wrapper/slot.rs, the loop in the slot's run). Where a process of the slot was killed for memory (hit_its_limit: oom_kill > 0, src/node/slots.rs), the compile runs again in a new slot and writes its outputs again, while dependents compiled against the first outputs may already be running.
A failed placement removes what it placed by NAME (unplace, src/node/daemon/place.rs), not the inode it placed.

What a second reader concluded (a read-only pass over 9faf6c61; I have not verified each citation). The freer, flattening a session's build and hardlinks are ruled out as long as holds are kept (snapshots.rs:830-873, made.rs:353-358, daemon/place.rs:41 and 125-138, depth.rs:142-163, cas/copy.rs:108-131). The best fit is the path where one job compiles a crate and others join it: a joiner gets the holder's .rmeta early and announces it to cargo (daemon/lookup.rs:178-182, 254-280) and the final entry later (189-196). Point 2 above then explains the E0460. The three E0463 are NOT explained for container jobs: by 632265aa's findings E0463 means rustc found the handed file empty, and the only path found that makes a handed name absent is unplace followed by the retry after a freer pass (conn.rs:233-241).

What cannot be had any more. The four jobs' directories are gone from the node, the worker's log of those minutes has rotated, and no counter says how often a slot's compile ran again or a placement was undone.

Proposed, in this order.

Make the next one readable: the refusal records each handed file's inode, ctime and content hash as the compile starts and as it fails, and two counters say how often a compile ran again after its slot's limit and how often a placement was undone. Small, in the wrapper and the daemon.
The invariant I think is missing: a crate file in a job's /target, once announced to cargo, never changes or disappears while that job runs. A compile that passed is not run again over its own outputs; a failed placement removes only what it placed.

Slots and the wrapper's slot loop are yours, so I commission nothing for 2 without your word. I would take 1, but I cannot land anything with a whole check set while t's test checks are refused on testing (issue #62).

A fifth job, with no disk squeeze (08:11Z 11-14, on `67588367`)

08:11:22 ERROR t::server::nodes::history: the compiler cache failed the job: refused: the compiler couldn't find crate `video_editor` cargo handed it (/target/debug/deps/libvideo_editor-ad3913b91a3d650c.rlib, 37574154 bytes as the compile started, 37574154 bytes now): error[E0463]: can't find crate for `video_editor` on t-worker-ci-x86-1 job=j566-78417 check="test" cause="cache_unreachable"

j566-78417 is a person's test driver job of run rb1e0d46e95, 08:01:42Z to 08:11:22Z. It ended error. The check ran again at 08:14:27Z and passed.
The node had 1,230 to 1,271 GB free and nothing deleting at the time. So the squeeze of 11-13 is not needed for this.
The file had the same size as the compile started and after, as in the earlier cases. Size alone cannot say whether the file was replaced, rewritten in place, or untouched and already wrong.
Jobs ended with cause cache_unreachable in the last 40 hours: seven. Two are another fault: j546-36793 (22:37Z 11-12) and j546-56152 (01:30Z 11-13) were people's ad-hoc cargo build --release --locked --target-dir … commands, the case of issue #50. The other five are this fault: the four of 21:54Z to 21:57Z 11-13 and j566-78417 today. All seven were people's jobs.

I am taking step 1 of the proposal now, as testing runs whole check sets again: the refusal will keep each handed file's device, inode and times from the one metadata call it already makes as the compile starts, read them again on the refusal path only, say which of the three cases it is, and give the file's content hash as it is then. Nothing is added to a compile that passes. Step 2 stays yours.

Step 1 is on main: `6c438411` (08:26Z 11-14)

The refusal keeps each handed file's device, inode, modification and change times from the one metadata call it already made as the compile starts. Nothing is hashed there and a passing compile does nothing new.
On a refusal only, it reads the file again and says which case it is, then gives its content hash as the cache names blobs:
- …, 25 bytes as the compile started, 25 bytes now; the same file, unchanged since the compile started (inode N, modified T, changed T); content blake3 <hex>
- …; another file now (inode A as the compile started, inode B now); content blake3 <hex>
- …; the same file rewritten since the compile started (inode N; modified T1, changed T1 as it started, modified T2, changed T2 now); content blake3 <hex>
The message still begins "the compiler couldn't find crate … cargo handed it" and ends with the compiler's own diagnostic.
It is in the wrapper, so production says this from the next promote of a main at or past 6c438411. The next refusal after that names its case, and the hash can be set beside what the node placed at that path.

Seen beside it and not changed: slot.rs near line 92 names only E0463 where E0786 and E0460 are refused too; the refusal describes the first --extern of a crate name if cargo passes a name twice.

08:39Z: the upgrade to 6c438411 is proven on testing with jobs running. It was deployed over fe81dd07 while 13 jobs with courses ran, the worker re-attached all 13, and the check set under it passed 8 of 8. Nothing more is needed from my side before a promote that carries it.
08:57Z: production serves c6dca088, which carries 6c438411. From now a refusal on production names its case and gives the file's hash.

Production, 9faf6c61 (the build before your 22:08Z promote). The wrapper, slot and placement files named below are unchanged in 6ebaa239, so this stands for the build production runs now. Nothing was changed on production; no code of mine is in flight. **What happened.** No job had ended this way in the 5 h 20 min since the 16:32Z restart. Then four people's jobs ended `cache_unreachable` within three minutes, 21:54:49 to 21:57:51Z 11-13: - j559-80704, `cargo build -p tilo-web-desktop` for wasm (started 21:49:32): E0463, can't find crate `tilo_delivery_protocol` (the `.rmeta` cargo handed it, 627071 bytes as the compile started and now). - j559-80090, test/ebook (21:40:48): E0463, `runtime_collab` (9820695 bytes, both times). - j559-80075, test/contacts (21:40:35): E0460, "found possibly newer version of crate `tilo_dav` which `cloud_source_dav` depends on". - j559-80080, test/notes (21:40:35): E0463, `package_store` (1032246 bytes, both times). The last three are one session's checks, running together; the first is another person's. All were run again on the same node. All four passed (the last at 22:18:06Z). So the files were wrong for a moment, not for the inputs. **What else was true then.** A wave of 86 people's jobs started within ten minutes. The node's free disk fell from 1,203 to 664 GiB and reached its floor at 22:05Z; the freer made one large pass at 21:52:32 to 21:53:20Z. Kept memory passed the offer in 21 of 120 samples of the half hour (highest 117%), and `t_sched_grow_total` rose from about 25 to 67 and then 125 per ten minutes. No job ended for memory. **What I read in the code (verified by me).** 1. The refusal records only the SIZE of each handed file before and after (crates/t-cache/src/cargo/wrapper/run.rs, `Handed::of` and `file`). A file replaced by another of the same size, or emptied and rewritten, reads the same as an untouched one. That is why these four lines cannot tell us what happened. 2. After every run that returned, passing ones too, the wrapper asks `Request::Again` (wrapper/slot.rs, the loop in the slot's run). Where a process of the slot was killed for memory (`hit_its_limit`: `oom_kill > 0`, src/node/slots.rs), the compile runs again in a new slot and writes its outputs again, while dependents compiled against the first outputs may already be running. 3. A failed placement removes what it placed by NAME (`unplace`, src/node/daemon/place.rs), not the inode it placed. **What a second reader concluded (a read-only pass over 9faf6c61; I have not verified each citation).** The freer, flattening a session's build and hardlinks are ruled out as long as holds are kept (snapshots.rs:830-873, made.rs:353-358, daemon/place.rs:41 and 125-138, depth.rs:142-163, cas/copy.rs:108-131). The best fit is the path where one job compiles a crate and others join it: a joiner gets the holder's `.rmeta` early and announces it to cargo (daemon/lookup.rs:178-182, 254-280) and the final entry later (189-196). Point 2 above then explains the E0460. The three E0463 are NOT explained for container jobs: by 632265aa's findings E0463 means rustc found the handed file empty, and the only path found that makes a handed name absent is `unplace` followed by the retry after a freer pass (conn.rs:233-241). **What cannot be had any more.** The four jobs' directories are gone from the node, the worker's log of those minutes has rotated, and no counter says how often a slot's compile ran again or a placement was undone. **Proposed, in this order.** 1. Make the next one readable: the refusal records each handed file's inode, ctime and content hash as the compile starts and as it fails, and two counters say how often a compile ran again after its slot's limit and how often a placement was undone. Small, in the wrapper and the daemon. 2. The invariant I think is missing: a crate file in a job's `/target`, once announced to cargo, never changes or disappears while that job runs. A compile that passed is not run again over its own outputs; a failed placement removes only what it placed. Slots and the wrapper's slot loop are yours, so I commission nothing for 2 without your word. I would take 1, but I cannot land anything with a whole check set while t's test checks are refused on testing (issue #62). ## A fifth job, with no disk squeeze (08:11Z 11-14, on 67588367) ``` 08:11:22 ERROR t::server::nodes::history: the compiler cache failed the job: refused: the compiler couldn't find crate `video_editor` cargo handed it (/target/debug/deps/libvideo_editor-ad3913b91a3d650c.rlib, 37574154 bytes as the compile started, 37574154 bytes now): error[E0463]: can't find crate for `video_editor` on t-worker-ci-x86-1 job=j566-78417 check="test" cause="cache_unreachable" ``` - j566-78417 is a person's `test` driver job of run rb1e0d46e95, 08:01:42Z to 08:11:22Z. It ended `error`. The check ran again at 08:14:27Z and passed. - The node had 1,230 to 1,271 GB free and nothing deleting at the time. So the squeeze of 11-13 is not needed for this. - The file had the same size as the compile started and after, as in the earlier cases. Size alone cannot say whether the file was replaced, rewritten in place, or untouched and already wrong. - Jobs ended with cause `cache_unreachable` in the last 40 hours: seven. Two are another fault: j546-36793 (22:37Z 11-12) and j546-56152 (01:30Z 11-13) were people's ad-hoc `cargo build --release --locked --target-dir …` commands, the case of issue #50. The other five are this fault: the four of 21:54Z to 21:57Z 11-13 and j566-78417 today. All seven were people's jobs. **I am taking step 1 of the proposal now**, as testing runs whole check sets again: the refusal will keep each handed file's device, inode and times from the one `metadata` call it already makes as the compile starts, read them again on the refusal path only, say which of the three cases it is, and give the file's content hash as it is then. Nothing is added to a compile that passes. Step 2 stays yours. ## Step 1 is on main: 6c438411 (08:26Z 11-14) - The refusal keeps each handed file's device, inode, modification and change times from the one `metadata` call it already made as the compile starts. Nothing is hashed there and a passing compile does nothing new. - On a refusal only, it reads the file again and says which case it is, then gives its content hash as the cache names blobs: - `…, 25 bytes as the compile started, 25 bytes now; the same file, unchanged since the compile started (inode N, modified T, changed T); content blake3 <hex>` - `…; another file now (inode A as the compile started, inode B now); content blake3 <hex>` - `…; the same file rewritten since the compile started (inode N; modified T1, changed T1 as it started, modified T2, changed T2 now); content blake3 <hex>` - The message still begins "the compiler couldn't find crate `…` cargo handed it" and ends with the compiler's own diagnostic. - It is in the wrapper, so production says this from the next promote of a main at or past 6c438411. The next refusal after that names its case, and the hash can be set beside what the node placed at that path. Seen beside it and not changed: `slot.rs` near line 92 names only E0463 where E0786 and E0460 are refused too; the refusal describes the first `--extern` of a crate name if cargo passes a name twice. - 08:39Z: the upgrade to 6c438411 is proven on testing with jobs running. It was deployed over fe81dd07 while 13 jobs with courses ran, the worker re-attached all 13, and the check set under it passed 8 of 8. Nothing more is needed from my side before a promote that carries it. - 08:57Z: production serves c6dca088, which carries 6c438411. From now a refusal on production names its case and gives the file's hash.

xemmerling referenced this issue

2026-11-13 22:28:18 +00:00

The node reached its disk floor under a people's wave: the freer ran out of things it may free, 21:33-22:27Z 11-13 #64

No labels

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference

tilo/t#63

No description provided.

Rows
Columns