mosaicstack/stack
25
0 Fork 1
Code Issues 419 Pull Requests 13 Packages Projects Releases 15 Wiki Activity

row 251: BUILD.md slot results, part A reds at the predicted fractions only, fix 18/18, bus suite green 3 times and concurrently (sage-2154)

Browse Source
This commit is contained in:
jason.woltje committed 2026-10-21 16:08:58 -05:00
1 parent 68f2dfd4b7
commit 27f01ef63a
1 file changed
+86 -1
Download Patch File Download Diff File Expand all files Collapse all files
agents/darkwing/work/queue-251/BUILD.md
+86 -1
View File
@@ -103,4 +103,89 @@ checks and chained with `&&`, TMPDIR under `/mnt/storage/scratch/tmp`.
## Slot results
Not run yet.
Sage's CLEAR came in sage-2154 at 20:58:55Z. `slot-251.sh` ran parts A and B from 20:59:22Z to 21:01:33Z,
on node v26.8.1 and OpenSSH_10.5p1, with TMPDIR `/mnt/storage/scratch/tmp/r251`. At the start, BOOTTIME
minus MONOTONIC read 0.000001 s, then 0.000000 s twice (dewey-0769 N1). So the hrtime fractions below
put the agent's second boundary in the right place.
### Part A: T27 alone under `align-hooks.mjs`, 3 runs per fraction
The fraction is when the hook started `ssh-add`. The hook logged each start within 0.0001 of its target.
| fraction | e5e4b2e5a (`-t 1`) | 68f2dfd4b (`-t 2`) |
|---|---|---|
| 0.990 | 3 pass | 3 pass |
| 0.993 | 3 pass | 3 pass |
| 0.995 | 3 red | 3 pass |
| 0.996 | 3 red | 3 pass |
| 0.997 | 3 pass | 3 pass |
| 0.998 | 3 pass | 3 pass |
e5e4b2e5a went red 6 times out of 18, every time at a fraction the prediction named, so none of them
counted toward the stop. 68f2dfd4b passed all 18. The fix runs used 68f2dfd4b, whose test blob is the same
as c19b4167e's (280132c7).
Every red failed on the first list and got `"The agent has no identities.\n"`, with the agent alive and
its socket present. The step 1 message gave these hrtime fractions. "addKey start" is the mark before the
hook's wait, so its fraction is earlier than the ssh-add start.
| run | addKey resolved | first list mark |
|---|---|---|
| 0.995 rep 1 | 0.9992 (+317.6 ms) | 0.9993 |
| 0.995 rep 2 | 0.9991 (+846.5 ms) | 0.9991 |
| 0.995 rep 3 | 0.9988 (+845.0 ms) | 0.9988 |
| 0.996 rep 1 | 0.9999 (+839.8 ms) | 1.0000 |
| 0.996 rep 2 | 0.0004 (+845.0 ms) | 0.0004 |
| 0.996 rep 3 | 0.0002 (+835.9 ms) | 0.0002 |
At 0.995 the add finished about 4 ms in, before the boundary, and the list mark came just before it. The
`ssh-add -l` process then reached the agent after the boundary. At 0.996 the agent stored the key before
the boundary, and addKey resolved just after it. In both cases the key's whole second ended between the
add and the list, which is the cause step 2 gives. The two edge fractions came out green on the first
build. At 0.993 the list still reached the agent before the boundary, and at 0.997 the add landed after
it, so the key got almost a full second. The prediction allowed either result at those two.
### Part B: `host-run.test.mjs` whole on 68f2dfd4b
24 tests, 24 passed (21:01:18Z, 14.0 s).
### The stop before C1, and the resume
At 21:01:33Z the script stopped before C1, with exit 4 and no red. My own `busy.sh` matched two `sleep 60`
processes, mine, in `darkwing-r251/packages/bus`. Part B left them. They come from T27 "the start sweep
keeps a live bus dir and kills only a matching live process" (`host-run.test.mjs:528` and `:536`). Its
`t.after` SIGKILLs the `/bin/sh -c 'sleep 60; :'` parent, but the `sleep` child lives on for up to 60 s.
That code is outside this row's diff, so the row leaves it alone, and it's recorded below as a follow-up.
Sage confirmed (sage-2159) that the right move is to resume only the scope that hadn't run.
`slot-251-cd.sh` runs C and D as `slot-251.sh` has them, with the same two busy checks. Before each check,
it waits up to 75 s for those orphans to exit: my uid, my trees, a command line of exactly `sleep 60`.
It logs them as it waits. Any other process still trips the checks.
### Parts C and D: the bus suite whole on 68f2dfd4b
| run | start | tests | pass | fail | time |
|---|---|---|---|---|---|
| C1 | 21:02:48Z | 598 | 598 | 0 | 21.6 s |
| C2 | 21:04:06Z | 598 | 598 | 0 | 21.4 s |
| C3 | 21:05:26Z | 598 | 598 | 0 | 22.1 s |
| D1, darkwing-r251 | 21:06:44Z | 598 | 598 | 0 | 24.2 s |
| D2, darkwing-r251b, TMPDIR `r251-b` | 21:06:44Z | 598 | 598 | 0 | 24.2 s |
The script waited 33 s before C2, 34 s before C3, 33 s before D and 32 s before the sweep. Each time it
was waiting for that run's `sleep 60` orphans (two per suite, four after D), and nothing else. After the
wait, the sweep of my trees, the out dir and TMPDIR found 0 processes left (21:08:04Z). Sage confirmed
(sage-2159, sage-2160) that the short gitea-api and `node --check` runs they made during the slot weren't
stops. None of my busy checks refused on any of them.
These runs used the bus files as they were at 3b0aef995. Since then, origin/refactor (666173292, then
7247d80c7 and c3d88840c with row 196) has changed `broker.mjs`, `runtime.mjs` and `server.mjs`, which T27's
file imports, along with other bus files. None of those commits touch this row's two paths or
`host-run.mjs`, and `git merge-tree` of c3d88840c with 68f2dfd4b is clean. The gate rerun in
a clean worktree on Sage's slot runs T27 against them.
### Follow-up, not in this row
T27's start-sweep test leaves the `sleep 60` child of each planted shell running for up to 60 s after
the test. Killing the process group (`process.kill(-pid)`; both shells are spawned `detached`) or
`exec sleep 60` in the shell would end the child along with its parent.