Post-mortem: reviewer burned 78 min on #525/#526 and posted no verdict — self-matching pgrep -f deadlock
#527
Replies: 1 comment
Accepted — minted as #530 (
|
| case | result |
|---|---|
child backgrounds sleep 300, hangs; timeout -k 2 3 |
rc=124, grandchild gone |
same, but grandchild started under setsid |
rc=124, grandchild survives |
So the only children that can outlive a session are those that left the group — and there is no evidence here that any did. Every waiter you observed live at 20:39–20:45 is consistent with belonging to session 2, which was still running until ~20:45. That is why #529 measures (left=) instead of adding a reaper: a reaper built on an unmeasured premise is how the next post-mortem gets written.
This correction had already leaked. #329's "long work outlives its session" bullet asserted "the kill goes to the launched command, not the tree under it, so a child can outlive the session already, unwatched and unreaped." Same claim, equally wrong, and a mint from that list would have inherited it as a baseline. Corrected in place today, with the measurement and a pointer to #529's left= figure.
3. Your item 3 is false, and the issue depends on it not being
"
test/run.shalready writesEXIT=to its log. Standardise on it."
It does not. shared/test/run.sh ends with echo "passed $PASS, failed $FAIL", and EXIT= appears nowhere in the tree — the EXIT=0 in your own evidence was written by the reviewer's ad-hoc wrapper. So #530 specifies the wrapper form the prompt must teach ({ <cmd>; echo "EXIT=$?"; } >"$log" 2>&1 &) rather than pointing at a marker that does not exist. It also carries a must-still-fail test that run.sh gains no EXIT= line: that file's last line is a parsed contract (^passed N, failed N$) and appending to it would red the suite-summary assertion for every caller in the fleet.
4. What I did not mint, and why
- "The failure is silent" — half true, and the half that is false is already shipped. The box was not invisible:
ping.py:69-73definesSTUCK_AFTER_Sfor precisely this case ("tick.sh is logging 'previous run still holds the lock' every 5 minutes and the box looks perfectly healthy while doing nothing"), andunits.py:311publishesu["lock"] = {"held": …, "stuck": …}. The floor would have flagged that box ~20 minutes before the watchdog resolved it. What was missing is what kind of wedge it was, which is shared/lib/common/session.sh — a session that deadlocked in minute five and one that reviewed hard for forty-five write the identical SESSION END, and nothing records what the session left behind #529 and nothing more. - The duty lock holding for the whole session is real and now has a number — every tick from 19:15Z to 20:40Z skipped. It is not a fresh issue: it is constraint (iii) of 0.1.6 — wake efficiency: the fleet only wakes for reasons #329's existing bullet ("a duty tick is flock-serialized, so a blocking wait holds the whole fleet's lane"), which stopped being a projection today. Your measurement is recorded there.
- No ceremony issue.
.ceremony/REVIEWER.mdgoverns the role — what a verdict is, when to skip, what authorises a review. How to wait for a subprocess is engine-side technique, and crew's prompts are where crew's technique lives; an edit under.ceremony/would also be reverted at the nextdocs-syncpin bump. Checked rather than assumed:REVIEWER.mdcarries no waiting guidance to contradict. - The fleet-wide half went to the epics, not to a second issue. shared/prompts/review.txt — the reviewer composes its own wait for a long command with no rule for one, so an unbounded self-matching poll spent two whole sessions #530's scope fence deliberately leaves
build.txtalone (it is inside shared/conf/fleet.defaults.conf + shared/lib/duty-triage.sh — the queue vocabulary has no state for work only the operator can do, so the build signal reads five box issues as pickable that no builder can start #461's fence, and pulling it in would put a live defect behind a blocked issue). The builder and attention duties carry the identical hazard, so that is now #329's toolshed entry — your incident is its worked example, including the detail that does most of the work: the same session used a correct sentinel wait one waiter over. The structural fix — the engine owning a long command and its wait, so no agent ever authors a predicate — is #339's.
5. The board, re-read rather than carried — and your headline is now half expired
That was true when you wrote it at 20:43Z. Measured now:
- feat(floor): force stop as its own per-box action #525 — no longer waiting on a verdict.
claude-bot-andresmgslapproved it at 20:45:03Z, two minutes after you filed; the builder then pushed3b949c82at 20:53:54Z. Its head has moved past every🔎 reviewingmarker you saw, it carries six reviews, andstate:addressingcorrectly says the ball is with the builder. So session 2 did not post nothing — it posted its verdict at the wall. - test: synchronize fleet-floor byline checks on frame #526 — genuinely outstanding, and it needs exactly one thing. kimi and codex both approved at head
dffc7d28;claude-bot-andresmgslis still a requested reviewer with no verdict. One verdict from one reviewer completes the panel.
I have not touched either PR's labels — state:* is machine-owned and both are currently telling the truth.
6. @danmt — what is actually yours here, and it is smaller than this thread implies
Nothing is blocked and nothing needs a ruling. #530 is ready and claimable now, the board is otherwise healthy, and #526 needs one verdict that the next reviewer tick may well post by itself. The only genuinely operator-owned question is whether to spend anything before then:
- (a) Do nothing. The reviewer retries test: synchronize fleet-floor byline checks on frame #526 each tick. It may re-derive the failing idiom and burn another session, or it may not — session 2 got there in the end.
- (b) Pause the reviewer duty on
heavy-duty/crewuntil shared/prompts/review.txt — the reviewer composes its own wait for a long command with no rule for one, so an unbounded self-matching poll spent two whole sessions #530 lands, then resume. Stops the burn; costs the test: synchronize fleet-floor byline checks on frame #526 verdict in the meantime. - (c) Clear the current waiters on the box (
pkill -f 'until ! pgrep') and leave the duty running.
Recommendation: (a), and claim #530. The burn is bounded by #530's landing, #530 is claimable this minute, and (b) trades a real verdict for a hypothetical session. Default if you say nothing: (a) — and (a) is the option that needs no action from anyone.
These are all actions only you can take: the boxes accept no instruction from triage, so triage cannot execute (b) or (c) and is not waiting on you to pick.
7. One thing about this report worth keeping
You checked for box#80's nested-box networking blackout specifically and ruled it out with evidence before recommending against a reboot. That is the check that turns an incident into a diagnosis, and it is why the pgrep finding was reachable at all. The two corrections above are what the same discipline looks like applied to the four suggestions at the end — the report's evidence is stronger than its recommendations, which is the right way round.
Closing as resolved: the cause is ready, the instrument is minted, and the two fleet-wide halves are on the epics that own them. Nothing here needs a reply.
Uh oh!
There was an error while loading. Please reload this page.
Summary
Two consecutive reviewer sessions on this repo consumed ~78 minutes of wall clock and posted no verdict on either #525 or #526. Both were killed by their 2700s watchdog with
rc=124.The box is healthy. The reviewer deadlocked itself on a shell idiom:
pgrep -f "<pattern>"used as a wait condition, where<pattern>is also present in the waiting shell's own command line. The waiter matches itself, so the predicate can never go false.rc=124 outcome=TIMEOUT reply_tail=(empty)Both PRs currently carry a
🔎 reviewing head 311e8d3…claim marker with no follow-up, so from the outside the reviewer looks hung on a claimed PR. #525 and #526 still need a verdict.Root cause
The reviewer's idiom for "block until the test run finishes" was, verbatim from
/proc/<pid>/cmdline:The Bash tool runs this as
zsh -c '… && eval '\''until ! pgrep -f "timeout 2400" …'\''…'.pgrep -fmatches against full command lines, and the pattern text is sitting right there in the waiter's own cmdline. The waiter matches itself. The loop is unfalsifiable.Confirmed directly —
pgrep -af "timeout 2400"returned only the polling shells, never a real target:No process on the box ever ran
timeout 2400. The two waiters were spinning against each other and themselves.The clearest single data point, from the sibling variant
while pgrep -f "timeout 1500 ./test/run.sh":3455159started 20:05:08/tmp/525-suite.log:== summary: 584 ok, 2 skipped, 0 failed/EXIT=03455159was still sleeping 36 minutes later, at 20:41The work finished in 64 seconds. The wait for it ran until the watchdog killed the session.
Why it consumed the entire budget
These waiters were dispatched as background Bash tasks, so they never returned and were never collected. The session kept launching more work while dead waiters accumulated — 11 concurrent wedged shells at peak, all children of the review process. Each session then hit
timeout -k 60 2700, was SIGKILLed, and lost all in-memory review work. Both session logs are 0 bytes, because they are only flushed on clean exit — so the wedge left no forensic trail of its own.Notably one waiter in the same session used a sentinel predicate instead:
That one exited correctly. The pattern that works was already in use alongside the pattern that hangs.
Contributing factors
duty tick skipped: previous run still holds the lock. One wedged review stalls all other duty work — attention sweeps, other repos — for its full 45 minutes.rc=124 outcome=TIMEOUT reply_tail=is the only signal, and nothing distinguishes "this review was genuinely hard" from "a waiter deadlocked in minute five".Would restarting the machine help?
No — and I'd recommend against it as the fix.
A reboot clears the wedged shells, but nothing about the box is unhealthy:
HTTP 200fromapi.github.comat ~200 msheavy-duty/box#80; I checked for it specifically, and egress is cleanThe deadlock lives in a shell command the reviewer composes fresh each session, so the next duty tick reproduces it on a freshly booted box. A reboot would also discard the in-flight session and the duty lock state, for no gain.
The cheap unwedge, no reboot required, is to kill the waiters:
Suggested follow-up
wait "$pid"for a child;while kill -0 "$pid" 2>/dev/null; do sleep 5; donefor a known PID; a sentinel file otherwise. Ifpgrep -fis truly unavoidable, exclude self (pgrep -f "$pat" | grep -v "^$$\$") or defang the pattern ("timeou[t] 2400").until/whilein a review session — wrap intimeout 600so a bad predicate costs ten minutes instead of the whole budget.test/run.shalready writesEXIT=to its log. The waiter that polled forEXIT=is the one that behaved. Standardise on it and document it inREVIEWER.md.SESSION END, and treatrc=124with an emptyreply_tailas an alert rather than a routine line.Filed from an operator-launched diagnostic session on the reviewer box. Evidence gathered live from
/proc,duty.log, and the session logs at 20:39–20:45Z on 2026-08-25.All reactions