tilo/t

Watch

Fork 0

VM steps lose /src (#65): virtiofsd addresses the worker's source filesystem by file handle, which it cannot honour once the host evicts the inode #66

New issue

Open

opened 2026-11-13 23:09:35 +00:00 by xemmerling · 0 comments

xemmerling commented

2026-11-13 23:09:35 +00:00

Owner

For issue #65 (VM steps lose files of /src mid-job). What I read on production and in the code, and the change I intend. Nothing is changed on production yet.

What the guest's /src is. A running step's virtiofsd for its inputs shares /share; under it l0 is an xfs layer directory, l1 the job's guest-network directory on xfs, and l2 the FUSE mount t-sources the job's own t __observe serves (read from the daemon's /proc/<pid>/mountinfo). The daemon is virtiofsd 1.14.0, started as --shared-dir /share --sandbox none --cache always --announce-submounts --xattr --readonly …, with nothing said about file handles.

virtiofsd addresses those inodes by file handle. Its default is --inode-file-handles=prefer (its own help). In every running step's vm-sockets/writable.log it says Filesystem mounted on "/share/target" …: Filesystem does not support file handles, falling back to O_PATH FDs; in none of the same steps' inputs.log does it say so. Inputs daemons with hundreds of open files hold two O_PATH descriptors each: no inode is pinned by a descriptor.

t-sources hands out handles it cannot honour. Its init asks for passthrough and idmap only, no FUSE_EXPORT_SUPPORT, and every entry has generation 0 (src/node/observe.rs:1029, 1064). The kernel still encodes a handle for such a filesystem, but can open it again only while the inode is in its cache. Once the host has evicted the inode, open_by_handle_at returns ESTALE. That is the error the guests see on a directory they had read earlier in the same step; a retried walk turns it into "no such file or directory".

All three shapes in #65 are that one. The "bulk transfer" errors end in readdirent /os/usr/lib/firewalld: stale file handle; the python one is ESTALE listing a directory; the third is ENOENT for a name in the tree. Ruled out by readings: descriptors (28 to 421 open against a limit of 1,048,576), an expiry (four failing steps ran 208 s, 274 s, 335 s and 793 s), the worker's in-place upgrades (today's failing jobs ran 03:13-03:19, 11:09-11:13, 20:35-20:49, 21:23-21:28 and 21:38-21:54Z; promotes at 10:56, 15:13, 16:31, 22:08Z). A second reader of 6ebaa239 found the layers immutable and held for the job's life, and no eviction, forget or sweep in t-sources itself.

Not shown: a reproduction on demand (it would need the host's inode cache dropped under a running guest), and why the reports begin on 11-11. Host memory pressure decides how soon an inode is evicted, and that grew from 11-11.

What I intend, in src/node/observe.rs, building on what is there: ask the kernel for FUSE_EXPORT_SUPPORT and answer the two lookups it then sends for a handle, . with the inode itself and .. with its parent, under the same inode number and generation 0. t-sources keeps every inode number for its server's life and never forgets one, so both answers are at hand. It costs no memory and leaves handles in use on the xfs layers. The alternative, --inode-file-handles=never in src/node/vm.rs, is one line but pins every inode a guest touches on the whole inputs share, the image's root included, in the step's memory.

The file is yours; I change nothing that is there. Say so if you would rather have the other fix or do it yourself.

A second fault, yours to place: a guest that cannot read its sources exits non-zero, is judged Fail (src/node/run/judge.rs:299) and Fail is kept (src/jobs/flight.rs:703-705), so the next run on the same inputs repeats the failure without running. Nothing tells this from the code's own failure. Until the first fix is live, an asker has to --force.

23:25Z 11-13: reproduced on testing, on e5835fde (no fix). A VM check added in a scratch clone (never committed) walks and reads /src sixty times, three seconds apart; meanwhile I write 2 to /proc/sys/vm/drop_caches on testing's worker every five seconds, which evicts the host's unused dentries and inodes.

The guest keeps what it learned of /src (run r5b5e47f6e7): fails after 48 s, at its 14th walk and the fifth host drop, with cat: /src/src/server/nodes/liveness.rs: Stale file handle. Guest of 525 MiB.
Control, the guest drops its own caches before each walk (run rb58d8ba087): all 60 walks pass under 20 host drops. A guest that forgets its nodes walks again from the share's root by name, virtiofsd forgets its handles with them, and no old handle is opened again.

So the fault needs both halves named above: a node of /src the guest still holds, and the host having evicted its inode. The same check on testing serving the change must pass its sixty walks; I will add that run here.

23:39Z 11-13: the change is on main as 6ea02834 ("node/observe: a handle to a source inode opens again after the host forgot it"). It touches src/node/observe.rs and one sentence of docs/spec.md, nothing of what was there: init also asks for FUSE_EXPORT_SUPPORT (KERNEL_WANTS), and lookup first asks Sources::by_handle, which answers . with the inode itself and .. with its directory under the inode numbers given before, ESTALE for an inode never made, records nothing, and under Names::UntilUnits keeps the entry for no time.

Check set on testing, forced, for that tree (run r62f6a05da8): fmt, clippy/t, clippy/t-cache, clippy/t-wrapper, vm-cargo, test/t-wrapper, test/t-cache and test/t all pass. The four new tests ran inside test/t on Linux. One of them mounts the server and opens a handle again after its entry was dropped; it passed in 9 ms, and a pass alone does not tell me it had a mount in the sandbox, so I do not count it as the proof.
The proof is the same reproduction on testing once it serves 6ea02834, the sixty walks with the guest keeping its caches and the host dropping its own. It is queued behind testing's deploy of main's head; I add its result here and promote only if it passes. If it fails I revert on main.
Still live on production (6ebaa239) meanwhile: run ra05f4c4543, os-layer-image-x86_64, 23:27:15Z, COPY .cargo … readdirent /.cargo: stale file handle after 567 s; 20 of the hour's 21 image-chain jobs passed.

23:52Z 11-13: the same reproduction passes on testing serving 6ea02834. Run re5d1849a19: 60 walks of /src done; the guest kept its caches, 202 s, the host's dentry and inode caches dropped 16 times meanwhile. Without the change the same check failed after 48 s at its 14th walk (r5b5e47f6e7). Read while it ran: its inputs daemon shares l2 as FUSE t-sources, logs no fallback from handles and holds 2 O_PATH descriptors of 32 open files, so the handles were in use and were opened again; testing's worker ran the build 6ea02834.

I am promoting 6ea02834 to production now (it carries e5835fde too; no schema step and no node protocol change over 6ebaa239, so going back is a plain promote of 6ebaa239). After it I read the image chain's outcomes hourly and any failure's log. The second fault above (a failure of this kind kept as the step's answer) is untouched and still yours to place; answers kept from before will repeat until their inputs change or the asker forces.

23:54Z 11-13: 6ea02834 is on production. Promoted at 23:53:47Z with all four conditions holding (testing on it and it main's head; server and database undisturbed; 105 minutes since the last promote; no person's job queued, p90 wait 5 s). The server restored and followed its jobs within 17 s of starting; the worker fetched the build at 23:54:54Z and re-attached 55 jobs. In the first two minutes 75 jobs ended, none by a cause of t, and 95 started on the new build, 60 of them already ended: the source server's new init and lookups serve every job. Jobs started before the promote keep the source server they had; only jobs started after it get the change. I read the image chain's outcomes over the next hours and add what I find.

Result after one hour on production (read 00:54Z 11-14)

The fix (6ea02834) is on production since 23:53:51Z 11-13, and since 00:22Z inside c2d52b34.

Image chain (`os-*` jobs), by end time	Ended	Passed	Failed	Error
The 6 h before the 35 min before the fix	135	126	7	0
The 35 min before the fix	13	10	1	0
The hour since the fix	25	23	1	1

Of the 25, 20 started after the fix and 18 of those passed.
The error is os-dev-image-lean-x86_64 of run rdca525a54e, ended grown_out after 263 s: t's own growth. Its rerun with a larger guest passed after 823 s.
The failure is os-compile-x86_64 of run rfb0f5a188a: a program the step built panicked in clap (Command::get_arg_conflicts_with: The passed arg conflicts with an arg unknown to the cmd). That is tilo's own.
Neither log has a stale-handle line, a failed bulk transfer or a lost file under /src. No job failed at setup or was lost, and no VM step failed at its mount.

So in the first hour no image-chain job that started after the fix lost /src. An hour is short against a fault that came in bursts; I will read it again after a few hours of image-chain runs.

After four hours (03:54Z 11-14)

The fix stayed in through the promote of c2d52b34 at 00:22Z, which carries it.

Image chain (`os-*` jobs), by end time	Ended	Passed	Failed	Error	Cancelled
The four hours since the fix	72	69	1	1	1

Of the 72, 67 started after the fix and 64 of those passed.
The three that did not pass are the two of the first hour, named above, and os-assembler-x86_64 of run r764fb5c56f. That one was cancelled at 00:56:25Z with its run, which its asker stopped (asked 00:45:59Z, stop = cancel).
Since 00:56Z every image-chain job that ended has passed.

So in four hours no image-chain job that started after the fix lost /src. I count the fault as fixed. If a VM step loses /src again I will say so here.

For issue #65 (VM steps lose files of `/src` mid-job). What I read on production and in the code, and the change I intend. Nothing is changed on production yet. **What the guest's `/src` is.** A running step's virtiofsd for its inputs shares `/share`; under it `l0` is an xfs layer directory, `l1` the job's `guest-network` directory on xfs, and `l2` the FUSE mount `t-sources` the job's own `t __observe` serves (read from the daemon's `/proc/<pid>/mountinfo`). The daemon is virtiofsd 1.14.0, started as `--shared-dir /share --sandbox none --cache always --announce-submounts --xattr --readonly …`, with nothing said about file handles. **virtiofsd addresses those inodes by file handle.** Its default is `--inode-file-handles=prefer` (its own help). In every running step's `vm-sockets/writable.log` it says `Filesystem mounted on "/share/target" …: Filesystem does not support file handles, falling back to O_PATH FDs`; in none of the same steps' `inputs.log` does it say so. Inputs daemons with hundreds of open files hold two `O_PATH` descriptors each: no inode is pinned by a descriptor. **`t-sources` hands out handles it cannot honour.** Its `init` asks for passthrough and idmap only, no `FUSE_EXPORT_SUPPORT`, and every entry has generation 0 (src/node/observe.rs:1029, 1064). The kernel still encodes a handle for such a filesystem, but can open it again only while the inode is in its cache. Once the host has evicted the inode, `open_by_handle_at` returns ESTALE. That is the error the guests see on a directory they had read earlier in the same step; a retried walk turns it into "no such file or directory". **All three shapes in #65 are that one.** The "bulk transfer" errors end in `readdirent /os/usr/lib/firewalld: stale file handle`; the python one is ESTALE listing a directory; the third is ENOENT for a name in the tree. Ruled out by readings: descriptors (28 to 421 open against a limit of 1,048,576), an expiry (four failing steps ran 208 s, 274 s, 335 s and 793 s), the worker's in-place upgrades (today's failing jobs ran 03:13-03:19, 11:09-11:13, 20:35-20:49, 21:23-21:28 and 21:38-21:54Z; promotes at 10:56, 15:13, 16:31, 22:08Z). A second reader of 6ebaa239 found the layers immutable and held for the job's life, and no eviction, forget or sweep in `t-sources` itself. **Not shown:** a reproduction on demand (it would need the host's inode cache dropped under a running guest), and why the reports begin on 11-11. Host memory pressure decides how soon an inode is evicted, and that grew from 11-11. **What I intend, in src/node/observe.rs, building on what is there:** ask the kernel for `FUSE_EXPORT_SUPPORT` and answer the two lookups it then sends for a handle, `.` with the inode itself and `..` with its parent, under the same inode number and generation 0. `t-sources` keeps every inode number for its server's life and never forgets one, so both answers are at hand. It costs no memory and leaves handles in use on the xfs layers. The alternative, `--inode-file-handles=never` in src/node/vm.rs, is one line but pins every inode a guest touches on the whole inputs share, the image's root included, in the step's memory. The file is yours; I change nothing that is there. Say so if you would rather have the other fix or do it yourself. **A second fault, yours to place:** a guest that cannot read its sources exits non-zero, is judged `Fail` (src/node/run/judge.rs:299) and `Fail` is kept (src/jobs/flight.rs:703-705), so the next run on the same inputs repeats the failure without running. Nothing tells this from the code's own failure. Until the first fix is live, an asker has to `--force`. **23:25Z 11-13: reproduced on testing, on e5835fde (no fix).** A VM check added in a scratch clone (never committed) walks and reads `/src` sixty times, three seconds apart; meanwhile I write 2 to `/proc/sys/vm/drop_caches` on testing's worker every five seconds, which evicts the host's unused dentries and inodes. - **The guest keeps what it learned of `/src`** (run r5b5e47f6e7): fails after 48 s, at its 14th walk and the fifth host drop, with `cat: /src/src/server/nodes/liveness.rs: Stale file handle`. Guest of 525 MiB. - **Control, the guest drops its own caches before each walk** (run rb58d8ba087): all 60 walks pass under 20 host drops. A guest that forgets its nodes walks again from the share's root by name, virtiofsd forgets its handles with them, and no old handle is opened again. So the fault needs both halves named above: a node of `/src` the guest still holds, and the host having evicted its inode. The same check on testing serving the change must pass its sixty walks; I will add that run here. **23:39Z 11-13: the change is on main as 6ea02834** ("node/observe: a handle to a source inode opens again after the host forgot it"). It touches src/node/observe.rs and one sentence of docs/spec.md, nothing of what was there: `init` also asks for `FUSE_EXPORT_SUPPORT` (`KERNEL_WANTS`), and `lookup` first asks `Sources::by_handle`, which answers `.` with the inode itself and `..` with its directory under the inode numbers given before, `ESTALE` for an inode never made, records nothing, and under `Names::UntilUnits` keeps the entry for no time. - **Check set on testing, forced, for that tree** (run r62f6a05da8): fmt, clippy/t, clippy/t-cache, clippy/t-wrapper, vm-cargo, test/t-wrapper, test/t-cache and test/t all pass. The four new tests ran inside test/t on Linux. One of them mounts the server and opens a handle again after its entry was dropped; it passed in 9 ms, and a pass alone does not tell me it had a mount in the sandbox, so I do not count it as the proof. - **The proof is the same reproduction on testing once it serves 6ea02834**, the sixty walks with the guest keeping its caches and the host dropping its own. It is queued behind testing's deploy of main's head; I add its result here and promote only if it passes. If it fails I revert on main. - **Still live on production (6ebaa239) meanwhile:** run ra05f4c4543, `os-layer-image-x86_64`, 23:27:15Z, `COPY .cargo … readdirent /.cargo: stale file handle` after 567 s; 20 of the hour's 21 image-chain jobs passed. **23:52Z 11-13: the same reproduction passes on testing serving 6ea02834.** Run re5d1849a19: `60 walks of /src done; the guest kept its caches`, 202 s, the host's dentry and inode caches dropped 16 times meanwhile. Without the change the same check failed after 48 s at its 14th walk (r5b5e47f6e7). Read while it ran: its inputs daemon shares `l2` as FUSE `t-sources`, logs no fallback from handles and holds 2 `O_PATH` descriptors of 32 open files, so the handles were in use and were opened again; testing's worker ran the build 6ea02834. I am promoting 6ea02834 to production now (it carries e5835fde too; no schema step and no node protocol change over 6ebaa239, so going back is a plain promote of 6ebaa239). After it I read the image chain's outcomes hourly and any failure's log. The second fault above (a failure of this kind kept as the step's answer) is untouched and still yours to place; answers kept from before will repeat until their inputs change or the asker forces. **23:54Z 11-13: 6ea02834 is on production.** Promoted at 23:53:47Z with all four conditions holding (testing on it and it main's head; server and database undisturbed; 105 minutes since the last promote; no person's job queued, p90 wait 5 s). The server restored and followed its jobs within 17 s of starting; the worker fetched the build at 23:54:54Z and re-attached 55 jobs. In the first two minutes 75 jobs ended, none by a cause of t, and 95 started on the new build, 60 of them already ended: the source server's new init and lookups serve every job. Jobs started before the promote keep the source server they had; only jobs started after it get the change. I read the image chain's outcomes over the next hours and add what I find. ## Result after one hour on production (read 00:54Z 11-14) The fix (6ea02834) is on production since 23:53:51Z 11-13, and since 00:22Z inside c2d52b34. | Image chain (`os-*` jobs), by end time | Ended | Passed | Failed | Error | |---|---|---|---|---| | The 6 h before the 35 min before the fix | 135 | 126 | 7 | 0 | | The 35 min before the fix | 13 | 10 | 1 | 0 | | The hour since the fix | 25 | 23 | 1 | 1 | - Of the 25, 20 started after the fix and 18 of those passed. - The error is `os-dev-image-lean-x86_64` of run rdca525a54e, ended `grown_out` after 263 s: t's own growth. Its rerun with a larger guest passed after 823 s. - The failure is `os-compile-x86_64` of run rfb0f5a188a: a program the step built panicked in clap (`Command::get_arg_conflicts_with: The passed arg conflicts with an arg unknown to the cmd`). That is tilo's own. - Neither log has a stale-handle line, a failed bulk transfer or a lost file under `/src`. No job failed at setup or was lost, and no VM step failed at its mount. So in the first hour no image-chain job that started after the fix lost `/src`. An hour is short against a fault that came in bursts; I will read it again after a few hours of image-chain runs. ## After four hours (03:54Z 11-14) The fix stayed in through the promote of c2d52b34 at 00:22Z, which carries it. | Image chain (`os-*` jobs), by end time | Ended | Passed | Failed | Error | Cancelled | |---|---|---|---|---|---| | The four hours since the fix | 72 | 69 | 1 | 1 | 1 | - Of the 72, 67 started after the fix and 64 of those passed. - The three that did not pass are the two of the first hour, named above, and `os-assembler-x86_64` of run r764fb5c56f. That one was cancelled at 00:56:25Z with its run, which its asker stopped (asked 00:45:59Z, `stop` = cancel). - Since 00:56Z every image-chain job that ended has passed. So in four hours no image-chain job that started after the fix lost `/src`. I count the fault as fixed. If a VM step loses `/src` again I will say so here.

xemmerling referenced this issue from a commit

2026-11-13 23:39:07 +00:00

node/observe: a handle to a source inode opens again after the host forgot it

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#66

No description provided.

Rows
Columns