pty events --wait busy-spins on shared events dir writes and never returns when the session exits #218

Activity

1. schickling-assistant commented on Nov 5, 2026

   

   schickling-assistant

   on Nov 5, 2026

   ContributorAuthor

   More actions

   Correction from Agent Policy (via Upstream Manager):

   • The 124% CPU waiter already ran with a timeout: pty events --wait user.verification-done --json -t 7300. It used 124% CPU for 53 minutes, which is below its 7300 s deadline. During that time, the proof had already emitted its completion event and exited. So a missing -t does not explain this case.
   • Open questions:
     • Why did the waiter not match the completion event?
     • Why did it not end when the session exited?
     • Why did it spin?
   • Fleet Load reports two other waits that ran well past -t 7200. This suggests that the deadline path itself can fail to end the process.

   Both source pointers in the issue body remain hypotheses; nobody has reproduced them.

   Posted on behalf of @schickling

   field	value
   agent_identity	agent/compoundingtech/compounding-manager
   session	01a1d992
   agent_persona	generalist
   agent_supervisor	unavailable
   agent_tool	OMP
   agent_tool_version	18.12.5
   agent_runtime	OMP 18.12.5
   agent_model	anthropic/claude-opus-5-5
   worktree	unknown
2. myobie commented on Nov 5, 2026

   

   myobie

   on Nov 5, 2026

   Contributor

   More actions

   I reproduced this at 063ff7f, the reported build, and at main 8dd3fd42. Each run used a fresh registry with 20 sessions that set their title and rang the bell every 100 ms, the way an agent's spinner writes. The figures are from debug builds, so read them against each other, not as release costs.

   Why it spun. 063ff7f's follower woke on every filesystem notification, including its own reads. Each scan opened the followed log, and that open woke it again.

   • One waiter in an empty registry used 10.9 s of CPU in 9.6 s. Five used 29.5 s in 8 s, which is about the reported 6.2 cores.
   • 063ff7f also logged every title change, so each spinner frame rewrote its session's log.

   Main fixed both. ad48f88 ignores read notifications and coalesces wake-ups, and d5e370c stops logging titles. On main, one waiter used 0.00 s alone and 0.20 s in 6 s under the load. Five used 1.58 s in 8 s.

   Hypothesis 1, waking for other sessions' writes. This one is real on main, and it accounts for those 0.20 s. #219 makes a named follower wake only for its own sessions' logs and metadata. Under the same load that gives 0.08 s per waiter, and 0.50 s for five.

   Hypothesis 1, rereading the whole log. This happens only when the followed log itself changed, because an unchanged file is caught by its inode and length first. Every append replaces the log with a new file, so a reader has to open it again anyway. The prefix comparison is how it notices a retention rewrite, and retention caps the log at 1000 lines. I left it as it is.

   Why it ran past -t. 063ff7f parsed options only before the session name, as Node does. In pty events NAME --wait T --json -t 7300, it dropped --wait, --json and -t. The command was then a plain follow, with no deadline, text lines instead of JSON, and no end.

   • With the name first, it ran until I killed it. With the options first, it timed out at 6 s.
   • Main (ad48f88) reads options after the name too. But it still stops at the first token it doesn't know and drops everything after it. --timeout=7300, -t=7300, --wait=T or a typo still mean a wait with no deadline, forever, on main.
   • End event waits when their daemon dies, and keep followers idle (#218) #219 makes such a token an error: Unexpected argument: --timeout=7300, exit 1.

   Why it did not match. I can see three ways, and the exact command line tells them apart:

   1. The name came first, on 063ff7f. Then it was not a wait. It printed the event as a text line, [HH:MM:SS] NAME: user.verification-done, and kept following. I measured this.
   2. The event landed before the waiter started. A wait for any type but session_exit matches only events appended after it starts. That's on every build, and the README states it. I measured this too: an emit followed by a wait timed out. Only a session_exit wait also reads recorded state (fix: complete event waits from session lifecycle state #197).
   3. The event was never written, as the issue body's "payload had failed after 21 seconds" suggests.

   The waiter's argv would settle which one it was. So would pty events NAME --recent --type user.verification-done --json on a build that has --type, which main does. For case 2, a waiter has to be running before the step that emits.

   Why it did not end when the session exited. On 063ff7f a named follower never retired. A wait ended only on a match, at the deadline or on SIGINT. Main ends a wait when the session's exit is logged or recorded, or when its entry is removed (ad48f88, #197). Under the load, a session that exited without the event ended its wait in 2.9 s, with exit 1 and Session "ends" ended before a "user.verification-done" event was observed.

   Main still misses one case: a daemon that dies without recording an exit, from SIGKILL, OOM or a host restart. A user.* wait and a session_exit wait both ran until I killed them. #201 ends the session_exit wait. #219 ends both, along with a named follow.

   	063ff7f	main	#201 (draft)	#219
   a follower wakes on its own reads (the spin)	yes	fixed (ad48f88)
   every title frame is logged	yes	fixed (d5e370c)
   options after the name are dropped	yes	fixed (ad48f88)
   an unknown token drops the options after it	yes	yes		fixed
   no end when the session exits or is removed	yes	fixed (ad48f88, #197)
   no end when the daemon dies unrecorded, session_exit wait	yes	yes	fixed	fixed
   no end when the daemon dies unrecorded, other waits and follows	yes	yes		fixed
   every follower wakes on every session's writes	yes	yes		fixed
   a matched wait exits up to 250 ms late	yes	yes		fixed

   The last row turned up while I measured. The match was printed at once, but the process waited for the follower's next 250 ms poll before exiting. On main, other sessions' writes often woke the follower first, which hid it.

   The reported build predates every fix above. 063ff7f is from 2026-10-19. Release v0.13.0-rust.6 has ad48f88, d5e370c and #197, so it ends the spin, the dropped deadline and the missing end on exit. #219 covers the rest.
3. myobie

   added a commit that references this issue on Nov 5, 2026

   Merge pull request #219 from compoundingtech/agent/events-waits-end-a…

   ...

   d50ad1b
4. myobie commented on Nov 5, 2026

   

   myobie

   on Nov 5, 2026

   Contributor

   More actions

   Fixed by #219, merged as d50ad1b. Decision 0021 records the new unknown-argument error.

   The reported build, 063ff7f, predates every fix, so the reporting host needs a new release:

   • v0.13.0-rust.6 already ends the spin, the dropped deadline after the name, and the wait that outlived its session (ad48f88, d5e370c, fix: complete event waits from session lifecycle state #197).
   • End event waits when their daemon dies, and keep followers idle (#218) #219 is not in a release yet. It adds the error for an unknown argument such as --timeout=60, the end of a wait when the daemon dies without recording an exit, followers that wake only for their own files, and a prompt exit after a match.

   Release note: pty events now rejects an unknown argument instead of ignoring it and every option after it. Pass -t <sec> (not -t=60 / --timeout=60) and --wait <type>. A wait or named follow now ends when its session's daemon dies without recording an exit.
5. myobie

   closed this as completedon Nov 5, 2026