A run waits on the background tasks its turn leaves running, and is told to write its report before a server holds it #128

Merged
agra merged 3 commits from task/3687-a-run-whose-turn-ends-while-its-backgrou into master 2026-10-24 07:13:28 +03:00
Owner

Tracker: #3687

A run whose turn ended while its own background tasks ran was killed idle_timeout 15 minutes later with no report, as review run 343 was (stream 7547): the session stayed up only for its tasks' turns, and a silent bench or a server that never ends gave it none within the idle cap.

What the PR delivers:

  • The stream-json adapter reads the session's running background tasks from each background_tasks_changed line, the whole set on each line, keeping each task's description.
  • Once the session has been told the run is over, a task it lists counts as activity, so the idle cap does not end a run whose agent waits on its tasks. The wall cap still applies.
  • The first turn to end with $SAK_REPORT written ends the run done through SIGTERM to the harness's group, which also ends a task still running, such as a server.
  • A turn that ends with no message pending, a background task listed and no report written gets one line from the runner before the session is told the run is over. The line names the running tasks by description, says the run stays up while they run, and says the turn that writes the report ends the run and every task still running, such as a server. The runner sends it once; the next turn's end closes the session's stdin as before. So an agent that ends its turn with only a server running is asked for its report instead of being held to the wall cap.
  • runner/README.md states these rules.

What it leaves: an agent that ignores the line and ends its turn again without the report, while only a server runs, is still held to the wall cap.

Regressions, both runner_core checks on the stub stream-json harness:

  • check_background_wait: the stub's turn leaves a server and a bench running; the bench ends silently after 3 s, past the check's 1.5 s idle cap, and the turn its notification opens writes the report while the server runs on. Fail-before with master 3ecd9d1's runner/: the run ends killed · idle_timeout 1 s after it starts, RUNNER CORE FAIL (1 checks).
  • check_server_report: the stub's first turn ends with only a server listed and no report; on the runner's line it writes the report, ends its turn and stays up, as it also does when its stdin closes instead. The check asserts the stream holds the line naming the server, the stream is done with the report's summary and the run is done, under a 10 s wall cap. Fail-before with c3bd8a7's runner files and this PR's tests (gate cache sx 300086027f): the run ends killed · wall_timeout 10 s after it starts, and the check FAILs. In the same run, check_wakeup and check_background_wait FAIL exit_status, because their stub modes now wait for the runner's line before they read to the end of their input. RUNNER CORE FAIL (3 checks). At 7170f5b all three pass.

The stub's wakeup and bench modes answer the runner's line with a turn of their own, and their listed tasks carry a description as the real line's do. check_wakeup counts three turns now: the first, the one the line opens and the one the task's notification opens.

No golden is added or changed.

It also carries fa0995c, "A silent tail's heartbeat follows the clock, not its count of polls" (src/api.sx), the same patch as ec78bde on #3721's branch and the fix of #3734. Agra chose to carry it here after the flow's gate step failed full twice at 7170f5b on m5 on one step_concurrency.sx check alone (jobs 74 and 80, below). A tail sent its : tick heartbeat every ten polls, counting each poll as POLL_MS. A poll is a 100 ms sleep plus three reads, and on a runner whose timers the system stretches, that sleep takes 100–250 ms. So the heartbeat came every 2.3–2.4 s, and a dropped tail kept renewing its slot past the check's fixed wait of one heartbeat plus the lease plus 1 s. The tail now sends the heartbeat once HEARTBEAT_MS has passed on the clock since it last sent framing, as docs/api.md describes the heartbeat. Whichever of this PR and #3721's lands second merges the patch cleanly.

Its regression is that step_concurrency.sx check, "the slot a dropped tail left behind is handed on once its lease lapses", run by hand with the gate cache's sx (300086027f) from git archive copies outside the checkout, the two arms side by side:

  • m5, 05:01 EEST: 7170f5b failed the check 3 of 3; 7170f5b with ec78bde's src/api.sx passed 3 of 3 (CONCURRENCY OK).
  • s32, 05:50–05:54 EEST (UserIsActive 0; 20 × 100 ms sleeps took 114/208/250 ms min/avg/max): 7170f5b failed the check 2 of 8, each time with the reclaiming tail refused 503 "every held slot is taken"; fa0995c passed 8 of 8.

Gates at the head fa0995c:

  • On s32, full gate run 262 (this run's #1, 05:53–06:19 EEST) failed only on three step9_release.sx install.sh checks, with env: Support/JetBrains/Toolbox/scripts: No such file or directory: s32's run PATH holds a directory with a space, and the test passes $PATH to env unquoted. Every step before it passed: both builds, npm run build with the web suite 390/390, the libc grep, and the whole tests/*.sx suite, step_concurrency and runner_core included. scripts/release.sh itself passed, its web suite 390/390 too. The steps after it did not run.
  • By hand on s32 right after it, with that one directory dropped from PATH and the gate cache's sx and chromium: scripts/release.sh passed, step9_release.sx passed (STEP9 OK, 39 ok), and the deploy contract passed. The runner Playwright config passed 10 of 10, on port 18978 for that one run, because an orphaned sak serve (pid 6685, left by run 75 on 2026-10-21) still holds 18988 on s32. The main Playwright config's first run (06:24–06:31, 6.8 min against its usual 3.6, with another run's gate starting halfway through it) failed 13 goldens: the eleven stream goldens whose hidden clocks move with a slow run (streams.spec.ts :1192, :1292 ×4, :1341, :1360 and tail-stream.spec.ts :157 ×4), and two accounts.spec.ts light sign-in shots by 79 pixels each. Run again with nothing changed (06:32–06:37, 4.5 min), it passed: 723 passed, 1 skipped. This PR changes nothing under web/.

Gates at 7170f5b, before fa0995c:

  • On s32, full gate run 1 failed at the release step. Every step before it passed: both builds, npm run build with the web suite 390/390, the libc grep, and the whole tests/*.sx suite, runner_core with both checks included. The release step's own web suite then failed 2 of 390: NavigatorRoute.test.ts "shows the counts of the loaded tracker" (a waitFor) and force.test.ts "spaces the anchors after an in-session grow…" (timed out in 5000 ms). full gate runs 2, 3 and 4 each failed at npm run build on the same two tests. Another run on s32 ran a WebKit bench through all four, holding the one-minute load at 6–13. This PR touches nothing under web/, which is identical to master's (full gate 213 passed with it at c3bd8a7). Alone, the two tests pass in 2.4 s. By hand, under the same load, the whole web suite failed 1 test with the default workers and passed 390/390 with --maxWorkers=4.
  • On m5, the flow's gate step (job 74, 02:43–03:14 EEST) failed in the tests/*.sx step on one check: step_concurrency.sx "the slot a dropped tail left behind is handed on once its lease lapses". Every step before it passed, the web suite 390/390 included, and so did every other test file. That file imports only src/, which this PR does not touch. Run by hand on m5 at 03:15 at the same head, the file passed (CONCURRENCY OK). The same check failed on m5 from 01:56 to 02:50 that night on another branch, and with master 3ecd9d1's src/ swapped in.
  • On m5, full gate run 1 of run 441 passed at 7170f5b (03:29–03:54 EEST): both builds, npm run build with the web suite 390/390, the libc grep, the whole tests/*.sx suite with step_concurrency and runner_core included, release with step9_release, the deploy contract, the main Playwright config (723 passed, 1 skipped) and the runner config (10 passed).
  • On m5, the flow's gate step again (job 80, 04:42–04:57 EEST, no other gate running on m5) failed on the same step_concurrency.sx check alone. Every step before it and every other test file passed, and the steps after it did not run. It is task #3734: at master the tail counts its idle polls as POLL_MS each, and m5's 100 ms sleeps took 132–250 ms (average about 235 ms) at 05:00, so a dropped tail renews its slot past the check's fixed wait. The fix, ec78bde ("A silent tail's heartbeat follows the clock, not its count of polls"), is on #3721's branch, not on master.
  • On m5, full gate run 256 (run 461's #1, 05:02–05:18 EEST) failed the same way at 7170f5b. Every step before tests/*.sx passed, the web suite 390/390 included, and step_concurrency.sx was the only failing file there. The steps after it did not run. By hand at 05:01 from git archive copies of 7170f5b, run side by side with the gate cache's sx, the file failed this check 3 of 3 as it is and passed 3 of 3 (CONCURRENCY OK) with ec78bde's src/api.sx applied.
Tracker: [#3687](https://sak.swipelab.com/tasks/3687) A run whose turn ended while its own background tasks ran was killed `idle_timeout` 15 minutes later with no report, as review run 343 was (stream 7547): the session stayed up only for its tasks' turns, and a silent bench or a server that never ends gave it none within the idle cap. What the PR delivers: - The stream-json adapter reads the session's running background tasks from each `background_tasks_changed` line, the whole set on each line, keeping each task's description. - Once the session has been told the run is over, a task it lists counts as activity, so the idle cap does not end a run whose agent waits on its tasks. The wall cap still applies. - The first turn to end with `$SAK_REPORT` written ends the run `done` through SIGTERM to the harness's group, which also ends a task still running, such as a server. - A turn that ends with no message pending, a background task listed and no report written gets one line from the runner before the session is told the run is over. The line names the running tasks by description, says the run stays up while they run, and says the turn that writes the report ends the run and every task still running, such as a server. The runner sends it once; the next turn's end closes the session's stdin as before. So an agent that ends its turn with only a server running is asked for its report instead of being held to the wall cap. - runner/README.md states these rules. What it leaves: an agent that ignores the line and ends its turn again without the report, while only a server runs, is still held to the wall cap. Regressions, both runner_core checks on the stub stream-json harness: - `check_background_wait`: the stub's turn leaves a server and a bench running; the bench ends silently after 3 s, past the check's 1.5 s idle cap, and the turn its notification opens writes the report while the server runs on. Fail-before with master 3ecd9d1's runner/: the run ends `killed · idle_timeout` 1 s after it starts, RUNNER CORE FAIL (1 checks). - `check_server_report`: the stub's first turn ends with only a server listed and no report; on the runner's line it writes the report, ends its turn and stays up, as it also does when its stdin closes instead. The check asserts the stream holds the line naming the server, the stream is `done` with the report's summary and the run is `done`, under a 10 s wall cap. Fail-before with c3bd8a7's runner files and this PR's tests (gate cache sx 300086027f): the run ends `killed · wall_timeout` 10 s after it starts, and the check FAILs. In the same run, `check_wakeup` and `check_background_wait` FAIL `exit_status`, because their stub modes now wait for the runner's line before they read to the end of their input. RUNNER CORE FAIL (3 checks). At 7170f5b all three pass. The stub's `wakeup` and `bench` modes answer the runner's line with a turn of their own, and their listed tasks carry a `description` as the real line's do. `check_wakeup` counts three turns now: the first, the one the line opens and the one the task's notification opens. No golden is added or changed. It also carries fa0995c, "A silent tail's heartbeat follows the clock, not its count of polls" (`src/api.sx`), the same patch as ec78bde on #3721's branch and the fix of #3734. Agra chose to carry it here after the flow's gate step failed `full` twice at 7170f5b on m5 on one `step_concurrency.sx` check alone (jobs 74 and 80, below). A tail sent its `: tick` heartbeat every ten polls, counting each poll as `POLL_MS`. A poll is a 100 ms sleep plus three reads, and on a runner whose timers the system stretches, that sleep takes 100–250 ms. So the heartbeat came every 2.3–2.4 s, and a dropped tail kept renewing its slot past the check's fixed wait of one heartbeat plus the lease plus 1 s. The tail now sends the heartbeat once `HEARTBEAT_MS` has passed on the clock since it last sent framing, as docs/api.md describes the heartbeat. Whichever of this PR and #3721's lands second merges the patch cleanly. Its regression is that `step_concurrency.sx` check, "the slot a dropped tail left behind is handed on once its lease lapses", run by hand with the gate cache's sx (300086027f) from `git archive` copies outside the checkout, the two arms side by side: - m5, 05:01 EEST: 7170f5b failed the check 3 of 3; 7170f5b with ec78bde's `src/api.sx` passed 3 of 3 (`CONCURRENCY OK`). - s32, 05:50–05:54 EEST (`UserIsActive 0`; 20 × 100 ms sleeps took 114/208/250 ms min/avg/max): 7170f5b failed the check 2 of 8, each time with the reclaiming tail refused 503 "every held slot is taken"; fa0995c passed 8 of 8. Gates at the head fa0995c: - On s32, `full` gate run 262 (this run's #1, 05:53–06:19 EEST) failed only on three `step9_release.sx` install.sh checks, with `env: Support/JetBrains/Toolbox/scripts: No such file or directory`: s32's run PATH holds a directory with a space, and the test passes `$PATH` to `env` unquoted. Every step before it passed: both builds, `npm run build` with the web suite 390/390, the libc grep, and the whole `tests/*.sx` suite, `step_concurrency` and `runner_core` included. `scripts/release.sh` itself passed, its web suite 390/390 too. The steps after it did not run. - By hand on s32 right after it, with that one directory dropped from PATH and the gate cache's sx and chromium: `scripts/release.sh` passed, `step9_release.sx` passed (`STEP9 OK`, 39 ok), and the deploy contract passed. The runner Playwright config passed 10 of 10, on port 18978 for that one run, because an orphaned `sak serve` (pid 6685, left by run 75 on 2026-10-21) still holds 18988 on s32. The main Playwright config's first run (06:24–06:31, 6.8 min against its usual 3.6, with another run's gate starting halfway through it) failed 13 goldens: the eleven stream goldens whose hidden clocks move with a slow run (`streams.spec.ts` :1192, :1292 ×4, :1341, :1360 and `tail-stream.spec.ts` :157 ×4), and two `accounts.spec.ts` light sign-in shots by 79 pixels each. Run again with nothing changed (06:32–06:37, 4.5 min), it passed: 723 passed, 1 skipped. This PR changes nothing under `web/`. Gates at 7170f5b, before fa0995c: - On s32, `full` gate run 1 failed at the release step. Every step before it passed: both builds, `npm run build` with the web suite 390/390, the libc grep, and the whole `tests/*.sx` suite, `runner_core` with both checks included. The release step's own web suite then failed 2 of 390: `NavigatorRoute.test.ts` "shows the counts of the loaded tracker" (a `waitFor`) and `force.test.ts` "spaces the anchors after an in-session grow…" (timed out in 5000 ms). `full` gate runs 2, 3 and 4 each failed at `npm run build` on the same two tests. Another run on s32 ran a WebKit bench through all four, holding the one-minute load at 6–13. This PR touches nothing under `web/`, which is identical to master's (`full` gate 213 passed with it at c3bd8a7). Alone, the two tests pass in 2.4 s. By hand, under the same load, the whole web suite failed 1 test with the default workers and passed 390/390 with `--maxWorkers=4`. - On m5, the flow's gate step (job 74, 02:43–03:14 EEST) failed in the `tests/*.sx` step on one check: `step_concurrency.sx` "the slot a dropped tail left behind is handed on once its lease lapses". Every step before it passed, the web suite 390/390 included, and so did every other test file. That file imports only `src/`, which this PR does not touch. Run by hand on m5 at 03:15 at the same head, the file passed (`CONCURRENCY OK`). The same check failed on m5 from 01:56 to 02:50 that night on another branch, and with master 3ecd9d1's `src/` swapped in. - On m5, `full` gate run 1 of run 441 passed at 7170f5b (03:29–03:54 EEST): both builds, `npm run build` with the web suite 390/390, the libc grep, the whole `tests/*.sx` suite with `step_concurrency` and `runner_core` included, release with `step9_release`, the deploy contract, the main Playwright config (723 passed, 1 skipped) and the runner config (10 passed). - On m5, the flow's gate step again (job 80, 04:42–04:57 EEST, no other gate running on m5) failed on the same `step_concurrency.sx` check alone. Every step before it and every other test file passed, and the steps after it did not run. It is task #3734: at master the tail counts its idle polls as `POLL_MS` each, and m5's 100 ms sleeps took 132–250 ms (average about 235 ms) at 05:00, so a dropped tail renews its slot past the check's fixed wait. The fix, ec78bde ("A silent tail's heartbeat follows the clock, not its count of polls"), is on #3721's branch, not on master. - On m5, `full` gate run 256 (run 461's #1, 05:02–05:18 EEST) failed the same way at 7170f5b. Every step before `tests/*.sx` passed, the web suite 390/390 included, and `step_concurrency.sx` was the only failing file there. The steps after it did not run. By hand at 05:01 from `git archive` copies of 7170f5b, run side by side with the gate cache's sx, the file failed this check 3 of 3 as it is and passed 3 of 3 (`CONCURRENCY OK`) with ec78bde's `src/api.sx` applied.
agra changed title from A run waits on the background tasks its turn leaves running, and the turn that writes its report ends it to A run waits on the background tasks its turn leaves running, and is told to write its report before a server holds it 2026-10-24 02:12:23 +03:00
The stream-json adapter keeps the description of each background task the
session lists running. The first turn to end with no message pending, a task
listed and $SAK_REPORT unwritten gets one user line from the runner, counted
as a message is, with no ack: it names the running tasks and says that the
run stays up while they run and that the turn that writes the report ends the
run and every task still running, such as a server. The next turn's end closes
the session's stdin as before, so an agent that ends its turn with only a
server running is asked for its report instead of being held to the wall cap.
A tail sent its `: tick` comment every ten polls, counting each poll as
POLL_MS. A poll is a sleep plus three reads, and on a runner whose timers
the system stretches a 100 ms sleep takes 215-250 ms, so the heartbeat
came every 2.3-2.4 s. A dropped tail's slot is renewed until its next
heartbeat write faults, so its lease lapsed later than one heartbeat plus
the lease, and step_concurrency's reclaim check failed on both runners.

The heartbeat now goes out once HEARTBEAT_MS has passed on the clock
since the tail last sent framing, as docs/api.md describes it.
agra merged commit 4bd074741f into master 2026-10-24 07:13:28 +03:00
Sign in to join this conversation.
No reviewers
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
sx/sak!128
No description provided.