tilo/t

Watch

Fork 0

node: a cut launch with a network is still followed as running: pasta lives in a PID namespace of its own, so runs_own takes it for the job's process #68

New issue

Open

opened 2026-11-14 01:06:34 +00:00 by xemmerling · 0 comments

xemmerling commented

2026-11-14 01:06:34 +00:00

Owner

A job whose launch was cut is meant to be told from a running one by whether a process of its own is in its cgroup (JobCgroup::runs_own, 7f174964, mine, 2026-11-12). The rule reads NSpid: a process named in more PID namespaces than the node's is the job's own. That rule takes pasta for the job's own process, so a networked job whose launch was cut is still followed as running until its stall bound, which is the case the commit set out to end (j319-1: its cgroup held pasta and t __observe alone).

Evidence

The test that covers it fails wherever it really runs. node::sandbox::tests::a_job_s_own_process_is_told_from_what_its_launch_started_for_it on the forge's runner (run 1454, with the assertion printing what it saw):

pasta and a helper alone: the cgroup holds ["30266 pasta.avx2 NSpid 30266 1", "30268 tilo-job-init NSpid 30268", "30305 sleep NSpid 30305"], and this test's process is t-5434c25ef6511 NSpid 30159

t-testing's test check declares root missing, so the test returns early there and has never run on a push (see #67).

Production shows the same. Read-only sample of the worker on ci-x86-1 at 01:05Z 11-14, helper and job processes by name and by how many PID namespaces they are named in (the node's is 1):

Process	argv[0]	Depth	Count
`passt.avx2`	`pasta`	2	85
`passt.avx2`	`passt`	1	6
`virtiofsd`	`virtiofsd`	1	12
`tilo-job-init` (helpers)		1	24
`tilo-job-init` (jobs' own)		2	66
`qemu-system-x86`		2	6

So every helper is in the node's namespace as the doc above PidNs says, except pasta: all 85 running pastas are one namespace below it.

Why. t starts pasta without --foreground (pasta_argv, src/node/sandbox.rs) and relies on it returning once it has connected the namespace. Upstream's isolate_prefork() at the snapshot t builds (passt-2026_10_02.cba3570, one unrelated patch) unshares a PID namespace for a pasta that goes to the background: if (!c->foreground || c->mode != MODE_PASTA) flags |= CLONE_NEWPID;. The doc above PidNs (src/node/cgroup.rs) says pasta "runs in the node's own", which is not so.

Effect

launch_cut (src/node/run/live.rs) returns nothing when runs_own is true. A job with a network whose worker died between its started and its process therefore is not ended as lost at once and rerun; its follower reads the cgroup as populated and follows it to its stall bound (600 s), then it ends in an error. Planned upgrades are not affected: the launch gate (d925bedf) lets no launch be cut by an exit the worker chooses. It bites when a worker dies unplanned.

What I am doing

One developer is taking it, on top of the #67 branch, where the failing test is the proof: pasta is told apart from the job's own processes by a fact that holds on a node (which one is being decided from the code and upstream's source, with the reasons written down), the doc is corrected, and the test passes on the forge's runner. Before it lands I prove an upgrade with running jobs on testing, since it changes what a worker reads of jobs an older worker started.

01:20Z 11-14: the fix, on trial (branch `dev/forge-ci`, commit `d5a910f8`)

Mechanism. Once pasta has connected, the launch records what lives below the node's PID namespace in the job's cgroup, by PID and start time, in the job's directory (started-for.json). At that point that is pasta's daemon alone: the record is taken in Net::start, before the source server, before started is written and before the job's own process is spawned, in a cgroup made for this launch. runs_own then counts a process below the node's namespace as the job's own unless its PID and start time are in that record.

Why a running job is never read as lost. Every way the record can be wrong or missing leaves at least as many processes counted as the job's own as before:

Case	What is read
No record (a job an earlier worker started)	Exactly as today
A record that cannot be read	As no record
A PID given again	Another start time, so it is the job's own
A stale record, or pasta gone	Nothing is excluded
A recorded process gone between two reads	Counts as the job's own

Considered and not taken. pasta's own --pid file (needs a file bound into pasta's mount namespace and a changed argument, and still a start time); a cgroup of pasta's own below the job's (every reader of a job's cgroup would have to step around it); pasta in the foreground (it never returns once connected, so the launch would have to poll).

Upgrade. It adds one file to a job's directory and changes no argument of pasta. Jobs an earlier worker started have no record and read as before; an earlier worker never reads the file. I prove this with running jobs on testing as soon as testing serves it, before it is promoted.

State. Reviewed. On the forge's runner as run 1456; t's own check set is running for it on testing.

01:32Z 11-14: the fix passes where the test really runs

Forge run 1456 on d5a910f8: fmt and clippy pass; test 3,326 run, 3,326 passed, 42 skipped. It is the first green test job of the forge's workflow since at least 11-05.

node::sandbox::tests::a_job_s_own_process_is_told_from_what_its_launch_started_for_it passed with the runner's stock pasta, the one that lives in a PID namespace of its own.
node::run::live::tests::a_job_whose_launch_was_cut_after_its_start_is_lost_and_never_followed passed with pasta below the node's namespace and a record.
node::run::live::tests::a_job_without_a_record_of_its_pasta_is_never_lost passed: a job of an earlier worker, or one whose record cannot be read, stays Running.

Main moved to 445e458e meanwhile, so the candidate was rebuilt on it (95935ccd) and t's own check set is running for it on testing. After it lands: the upgrade with running jobs on testing, both ways, before any promote.

01:38Z 11-14: landed as `95935ccd`

t's own check set on testing passed for it on main's head 445e458e (run r9d3662abef, 8 of 8), and it is on main as 95935ccd since 01:37:54Z. It is NOT promoted. Running now on testing: the upgrade with jobs under way (an earlier worker's jobs read by this one); then the reverse (this worker's jobs, with started-for.json, read by the earlier one). Please do not promote it before the result stands here.

01:50Z 11-14: the way back holds; the fix seen at work

The record, live on testing (worker on 95935ccd): all 15 job directories of a forced check set held started-for.json. One read [{"pid":615067,"start":66523111}], and that process was passt.avx2 with argv[0] pasta and NSpid: 615067 1: pasta's daemon and nothing else.
Way back (this worker's jobs read by the older one): with 19 job directories on the node, 445e458e was deployed. The worker fetched it at 01:46:14Z and logged re-attached to the jobs on disk jobs=14; reaped as unattachable 0, missing field 0, ERROR lines 0, panics 0. The run (ra87c34c88a) ended with all 8 checks passed.
Forward (the older worker's jobs, without a record, read by the fix): testing moved to the fix by itself at 01:44Z with no job on disk, which shows nothing, so it is being run by hand now.

01:57Z 11-14: the upgrade holds both ways with jobs under way

Direction	Jobs on the node at the deploy	Re-attached	Unattachable	`missing field`	Errors	The run
Way back: 95935ccd's jobs, each with `started-for.json`, read by `445e458e` (01:46:14Z)	19	14	0	0	0	ra87c34c88a: 8 of 8 checks passed
Forward: 445e458e's jobs, none with a record, read by `95935ccd` (01:53:10Z)	18	14	0	0	0	r3e15fc55ce: 8 of 8 checks passed, 39 of 39 jobs

One thing in the way-back run I could not read to the end: of its 13 test/t jobs under way across the takeover, one (j386-11) ended fail by a normal end, and the check passed with every shard once and no failed or retried test in its log. The failed attempt's own output is not kept, so I cannot say what failed in it. The forward run had no such job.

The forge's workflow is green for 95935ccd (run 1459). Testing serves it. It is not on production; nothing here stands in the way of a promote any more.

02:48Z 11-14: the node protocol step under it (`a3c41636`, 72 to 73), with jobs under way

Main's head a3c41636 raises the node protocol to 73, and a promote of main would carry this fix across that step. Testing had moved to a3c41636 by itself at 02:34Z with no job on disk, so I ran both directions by hand there:

Direction	When	Re-attached	Unattachable	`missing field`	Errors	The run
Way back: a3c41636's jobs read by `95935ccd` (protocol 73 to 72)	02:39:48Z	14	0	0	0	ra22d6f522a: 8 of 8 checks, 41 of 41 jobs
Forward: 95935ccd's jobs read by `a3c41636` (protocol 72 to 73)	02:44:00Z	13	0	0	0	r90904e8630: 8 of 8 checks, 41 of 41 jobs

In both the worker logged "server speaks node protocol N, this node speaks M: it runs the server's build", kept a job's end and its output until the server took them, fetched the server's build and re-attached within two seconds. Testing serves a3c41636 again.

One thing for whoever promotes a3c41636: t's own run on it on testing (rb3566d100f, 02:28 to 02:33Z) failed test/t on one test, drivers::cargo::tests_again::a_family_whose_own_wrapper_makes_cargo_refuse_is_answered_once ("every verdict from the cache", src/drivers/cargo/tests_again.rs:919). The same commit passed that test on the forge's runner (run 1460) and in the whole check set of the way-back proof, which was built from a3c41636's sources. One failure against two passes, with no deploy on testing in that window; I have not found its cause.

03:15Z 11-14: the next node protocol step (`1f4798be`, 73 to 74), with jobs under way

Main moved to 1f4798be at 02:56Z, which raises the node protocol once more. t's own run on it on testing passed 15 of 15, and testing moved to it by itself at 03:03Z with no job on disk. Both directions by hand again:

Direction	When	Re-attached	Unattachable	`missing field`	Errors	The run
Way back: 1f4798be's jobs read by `a3c41636` (protocol 74 to 73)	03:06:28Z	13	0	0	0	re94f4405ad: 8 of 8 checks, 39 of 39 jobs
Forward: a3c41636's jobs read by `1f4798be` (protocol 73 to 74)	03:10:20Z	13	0	0	0	rdc5d09b569: 7 of 8 checks, 38 of 39 jobs; `test/t` failed on one test, see below

Testing serves 1f4798be again. Production is on c2d52b34 with node protocol 72 and client protocol 64; main's head has node protocol 74 and the same client protocol, so a promote of main crosses two node steps at once. For people's clients: an older t keeps working against the newer server, since 2ec12d3c only adds an inputs field to results, left out when empty, and CheckResult takes fields it does not know. The other way round, a newer t that sends --input to a server before 2ec12d3c is refused, because RunRequest refuses unknown fields; without --input nothing is sent and it works. The mismatch test is plain equality of the header with the build's own number (proto::speaks, raised in Client::check_protocols), so a worker two steps away takes the same path as one step away: it runs the server's build. Shown by runs here: each single step with its neighbour, both ways. Not shown by a run: the jump of two, and the way back to c2d52b34 itself.

The red check in the forward run is not one of the re-attached jobs. All 13 jobs that were under way across the takeover passed, as did the 13 across the way back. The job that failed (j394-8) was started by the newer worker ten seconds after it took over, and failed one test after 86 s: drivers::cargo::tests_multi_tilo::a_tilos_sized_wave_runs_across_nodes_as_it_does_on_one, "CI's wave is handed out" (src/drivers/cargo/tests_multi_tilo.rs:307). On the forge's runner that test passes in 39 s.

It is the third single test failure in test/t on testing tonight, each a different test and each in a run that shared testing's one node with a restart or a second check set: an unread one at 01:48Z, drivers::cargo::tests_again::a_family_whose_own_wrapper_makes_cargo_refuse_is_answered_once at 02:33Z ("every verdict from the cache"), and this one. The same sources passed test/t whole in other runs and on the forge's runner each time. I read them as tests that fail under load on that node, not as an effect of the protocol steps; I have not found a cause in the code.

A job whose launch was cut is meant to be told from a running one by whether a process of its own is in its cgroup (`JobCgroup::runs_own`, 7f174964, mine, 2026-11-12). The rule reads `NSpid`: a process named in more PID namespaces than the node's is the job's own. That rule takes pasta for the job's own process, so a networked job whose launch was cut is still followed as running until its stall bound, which is the case the commit set out to end (j319-1: its cgroup held pasta and `t __observe` alone). ## Evidence **The test that covers it fails wherever it really runs.** `node::sandbox::tests::a_job_s_own_process_is_told_from_what_its_launch_started_for_it` on the forge's runner (run 1454, with the assertion printing what it saw): ``` pasta and a helper alone: the cgroup holds ["30266 pasta.avx2 NSpid 30266 1", "30268 tilo-job-init NSpid 30268", "30305 sleep NSpid 30305"], and this test's process is t-5434c25ef6511 NSpid 30159 ``` t-testing's `test` check declares `root` missing, so the test returns early there and has never run on a push (see #67). **Production shows the same.** Read-only sample of the worker on ci-x86-1 at 01:05Z 11-14, helper and job processes by name and by how many PID namespaces they are named in (the node's is 1): | Process | argv[0] | Depth | Count | |---|---|---|---| | `passt.avx2` | `pasta` | 2 | 85 | | `passt.avx2` | `passt` | 1 | 6 | | `virtiofsd` | `virtiofsd` | 1 | 12 | | `tilo-job-init` (helpers) | | 1 | 24 | | `tilo-job-init` (jobs' own) | | 2 | 66 | | `qemu-system-x86` | | 2 | 6 | So every helper is in the node's namespace as the doc above `PidNs` says, except pasta: all 85 running pastas are one namespace below it. **Why.** t starts pasta without `--foreground` (`pasta_argv`, `src/node/sandbox.rs`) and relies on it returning once it has connected the namespace. Upstream's `isolate_prefork()` at the snapshot t builds (`passt-2026_10_02.cba3570`, one unrelated patch) unshares a PID namespace for a pasta that goes to the background: `if (!c->foreground || c->mode != MODE_PASTA) flags |= CLONE_NEWPID;`. The doc above `PidNs` (`src/node/cgroup.rs`) says pasta "runs in the node's own", which is not so. ## Effect `launch_cut` (`src/node/run/live.rs`) returns nothing when `runs_own` is true. A job with a network whose worker died between its `started` and its process therefore is not ended as lost at once and rerun; its follower reads the cgroup as populated and follows it to its stall bound (600 s), then it ends in an error. Planned upgrades are not affected: the launch gate (d925bedf) lets no launch be cut by an exit the worker chooses. It bites when a worker dies unplanned. ## What I am doing One developer is taking it, on top of the #67 branch, where the failing test is the proof: pasta is told apart from the job's own processes by a fact that holds on a node (which one is being decided from the code and upstream's source, with the reasons written down), the doc is corrected, and the test passes on the forge's runner. Before it lands I prove an upgrade with running jobs on testing, since it changes what a worker reads of jobs an older worker started. ## 01:20Z 11-14: the fix, on trial (branch `dev/forge-ci`, commit d5a910f8) **Mechanism.** Once pasta has connected, the launch records what lives below the node's PID namespace in the job's cgroup, by PID and start time, in the job's directory (`started-for.json`). At that point that is pasta's daemon alone: the record is taken in `Net::start`, before the source server, before `started` is written and before the job's own process is spawned, in a cgroup made for this launch. `runs_own` then counts a process below the node's namespace as the job's own unless its PID and start time are in that record. **Why a running job is never read as lost.** Every way the record can be wrong or missing leaves at least as many processes counted as the job's own as before: | Case | What is read | |---|---| | No record (a job an earlier worker started) | Exactly as today | | A record that cannot be read | As no record | | A PID given again | Another start time, so it is the job's own | | A stale record, or pasta gone | Nothing is excluded | | A recorded process gone between two reads | Counts as the job's own | **Considered and not taken.** pasta's own `--pid` file (needs a file bound into pasta's mount namespace and a changed argument, and still a start time); a cgroup of pasta's own below the job's (every reader of a job's cgroup would have to step around it); pasta in the foreground (it never returns once connected, so the launch would have to poll). **Upgrade.** It adds one file to a job's directory and changes no argument of pasta. Jobs an earlier worker started have no record and read as before; an earlier worker never reads the file. I prove this with running jobs on testing as soon as testing serves it, before it is promoted. **State.** Reviewed. On the forge's runner as run 1456; t's own check set is running for it on testing. ## 01:32Z 11-14: the fix passes where the test really runs Forge run 1456 on d5a910f8: fmt and clippy pass; test 3,326 run, 3,326 passed, 42 skipped. It is the first green `test` job of the forge's workflow since at least 11-05. - `node::sandbox::tests::a_job_s_own_process_is_told_from_what_its_launch_started_for_it` passed with the runner's stock pasta, the one that lives in a PID namespace of its own. - `node::run::live::tests::a_job_whose_launch_was_cut_after_its_start_is_lost_and_never_followed` passed with pasta below the node's namespace and a record. - `node::run::live::tests::a_job_without_a_record_of_its_pasta_is_never_lost` passed: a job of an earlier worker, or one whose record cannot be read, stays `Running`. Main moved to 445e458e meanwhile, so the candidate was rebuilt on it (95935ccd) and t's own check set is running for it on testing. After it lands: the upgrade with running jobs on testing, both ways, before any promote. ## 01:38Z 11-14: landed as 95935ccd t's own check set on testing passed for it on main's head 445e458e (run r9d3662abef, 8 of 8), and it is on main as 95935ccd since 01:37:54Z. It is NOT promoted. Running now on testing: the upgrade with jobs under way (an earlier worker's jobs read by this one); then the reverse (this worker's jobs, with `started-for.json`, read by the earlier one). Please do not promote it before the result stands here. ## 01:50Z 11-14: the way back holds; the fix seen at work - **The record, live on testing (worker on 95935ccd):** all 15 job directories of a forced check set held `started-for.json`. One read `[{"pid":615067,"start":66523111}]`, and that process was `passt.avx2` with argv[0] `pasta` and `NSpid: 615067 1`: pasta's daemon and nothing else. - **Way back (this worker's jobs read by the older one):** with 19 job directories on the node, 445e458e was deployed. The worker fetched it at 01:46:14Z and logged `re-attached to the jobs on disk jobs=14`; reaped as unattachable 0, `missing field` 0, ERROR lines 0, panics 0. The run (ra87c34c88a) ended with all 8 checks passed. - **Forward (the older worker's jobs, without a record, read by the fix):** testing moved to the fix by itself at 01:44Z with no job on disk, which shows nothing, so it is being run by hand now. ## 01:57Z 11-14: the upgrade holds both ways with jobs under way | Direction | Jobs on the node at the deploy | Re-attached | Unattachable | `missing field` | Errors | The run | |---|---|---|---|---|---|---| | Way back: 95935ccd's jobs, each with `started-for.json`, read by 445e458e (01:46:14Z) | 19 | 14 | 0 | 0 | 0 | ra87c34c88a: 8 of 8 checks passed | | Forward: 445e458e's jobs, none with a record, read by 95935ccd (01:53:10Z) | 18 | 14 | 0 | 0 | 0 | r3e15fc55ce: 8 of 8 checks passed, 39 of 39 jobs | One thing in the way-back run I could not read to the end: of its 13 `test/t` jobs under way across the takeover, one (j386-11) ended `fail` by a normal end, and the check passed with every shard once and no failed or retried test in its log. The failed attempt's own output is not kept, so I cannot say what failed in it. The forward run had no such job. The forge's workflow is green for 95935ccd (run 1459). Testing serves it. It is not on production; nothing here stands in the way of a promote any more. ## 02:48Z 11-14: the node protocol step under it (a3c41636, 72 to 73), with jobs under way Main's head a3c41636 raises the node protocol to 73, and a promote of main would carry this fix across that step. Testing had moved to a3c41636 by itself at 02:34Z with no job on disk, so I ran both directions by hand there: | Direction | When | Re-attached | Unattachable | `missing field` | Errors | The run | |---|---|---|---|---|---|---| | Way back: a3c41636's jobs read by 95935ccd (protocol 73 to 72) | 02:39:48Z | 14 | 0 | 0 | 0 | ra22d6f522a: 8 of 8 checks, 41 of 41 jobs | | Forward: 95935ccd's jobs read by a3c41636 (protocol 72 to 73) | 02:44:00Z | 13 | 0 | 0 | 0 | r90904e8630: 8 of 8 checks, 41 of 41 jobs | In both the worker logged "server speaks node protocol N, this node speaks M: it runs the server's build", kept a job's end and its output until the server took them, fetched the server's build and re-attached within two seconds. Testing serves a3c41636 again. One thing for whoever promotes a3c41636: t's own run on it on testing (rb3566d100f, 02:28 to 02:33Z) failed `test/t` on one test, `drivers::cargo::tests_again::a_family_whose_own_wrapper_makes_cargo_refuse_is_answered_once` ("every verdict from the cache", `src/drivers/cargo/tests_again.rs:919`). The same commit passed that test on the forge's runner (run 1460) and in the whole check set of the way-back proof, which was built from a3c41636's sources. One failure against two passes, with no deploy on testing in that window; I have not found its cause. ## 03:15Z 11-14: the next node protocol step (1f4798be, 73 to 74), with jobs under way Main moved to 1f4798be at 02:56Z, which raises the node protocol once more. t's own run on it on testing passed 15 of 15, and testing moved to it by itself at 03:03Z with no job on disk. Both directions by hand again: | Direction | When | Re-attached | Unattachable | `missing field` | Errors | The run | |---|---|---|---|---|---|---| | Way back: 1f4798be's jobs read by a3c41636 (protocol 74 to 73) | 03:06:28Z | 13 | 0 | 0 | 0 | re94f4405ad: 8 of 8 checks, 39 of 39 jobs | | Forward: a3c41636's jobs read by 1f4798be (protocol 73 to 74) | 03:10:20Z | 13 | 0 | 0 | 0 | rdc5d09b569: 7 of 8 checks, 38 of 39 jobs; `test/t` failed on one test, see below | Testing serves 1f4798be again. Production is on c2d52b34 with node protocol 72 and client protocol 64; main's head has node protocol 74 and the same client protocol, so a promote of main crosses two node steps at once. For people's clients: an older `t` keeps working against the newer server, since 2ec12d3c only adds an `inputs` field to results, left out when empty, and `CheckResult` takes fields it does not know. The other way round, a newer `t` that sends `--input` to a server before 2ec12d3c is refused, because `RunRequest` refuses unknown fields; without `--input` nothing is sent and it works. The mismatch test is plain equality of the header with the build's own number (`proto::speaks`, raised in `Client::check_protocols`), so a worker two steps away takes the same path as one step away: it runs the server's build. Shown by runs here: each single step with its neighbour, both ways. Not shown by a run: the jump of two, and the way back to c2d52b34 itself. **The red check in the forward run is not one of the re-attached jobs.** All 13 jobs that were under way across the takeover passed, as did the 13 across the way back. The job that failed (j394-8) was started by the newer worker ten seconds after it took over, and failed one test after 86 s: `drivers::cargo::tests_multi_tilo::a_tilos_sized_wave_runs_across_nodes_as_it_does_on_one`, "CI's wave is handed out" (`src/drivers/cargo/tests_multi_tilo.rs:307`). On the forge's runner that test passes in 39 s. It is the third single test failure in `test/t` on testing tonight, each a different test and each in a run that shared testing's one node with a restart or a second check set: an unread one at 01:48Z, `drivers::cargo::tests_again::a_family_whose_own_wrapper_makes_cargo_refuse_is_answered_once` at 02:33Z ("every verdict from the cache"), and this one. The same sources passed `test/t` whole in other runs and on the forge's runner each time. I read them as tests that fail under load on that node, not as an effect of the protocol steps; I have not found a cause in the code.

xemmerling referenced this issue from a commit

2026-11-14 01:17:42 +00:00

node: pasta, in a PID namespace of its own, is told from a job's own processes by what its launch recorded of it

xemmerling referenced this issue

2026-11-14 01:19:32 +00:00

The forge workflow's test job has failed on every push to main since at least 11-05: eight tests fail on its runner without naming what they lack #67

xemmerling referenced this issue from a commit

2026-11-14 01:37:54 +00:00

node: pasta, in a PID namespace of its own, is told from a job's own processes by what its launch recorded of it