Skip to content

0.29.0: stuck request count, window start failure, shorter lock holds, sturdier state files and gate - #1

Merged
benbuschmann merged 17 commits into
mainfrom
audit-p1-p2
Oct 29, 2026
Merged

benbuschmann merged 17 commits into
mainfrom
audit-p1-p2

Conversation

@benbuschmann

Copy link
Copy Markdown
Owner

Eight fixes for 0.29.0. Two of them matter most. A Jobs API submit or withdraw at the wrong moment could leave a request counted forever, which quietly stopped all scheduling until a restart. And a start_cmd that failed at the end of an exclusive window left the service down with no explanation. The other six cut long waits under the transition lock, make wrong-shaped state files harmless, and tighten the gate.

Each fix is its own commit, and each comes with a test that failed on main before the change. The failing output below is trimmed.

A request counted forever after a Jobs API change

What went wrong. request_start counted the request, then looped over the job table and read the queue file once per job. A submit or withdraw during that loop raised dictionary changed size during iteration. The gate called request_start outside its try, so request_end never ran and inflight stayed at 1. From then on the service never looked idle: no parks, no gap jobs, and paused yield jobs stayed paused. snapshot, status, _track_progress, _track_speed and sample looped the same way and could fail one read or one tick.

Fix. Those loops now run over list(self.job.items()), status skips a job withdrawn since its snapshot, and the gate calls request_start inside the try whose finally runs request_end.

Test. tests/test_job_table_changes.py

before:
E       AssertionError: 1 != 0
E           RuntimeError: dictionary changed size during iteration
E           KeyError: 'late'
3 failed
after:
3 passed

A failed start_cmd at the end of an exclusive window

What went wrong. Only a successful start set starting_since. After a failure the service was neither stopped, starting nor dead, so requests got no 503 reason, no gap jobs were admitted, and the restart in _recover began only after a real request had failed its wake.

Fix. The failure branch sets dead_since. Requests get "failed to wake…; it is being restarted", and _recover, later in the same tick, runs stop_cmd and start_cmd once. Keeping stopped = True as well would not have worked, because _recover skips stopped services and _windows would re-run start_cmd every tick.

Test. tests/test_window_start_fails.py::test_failed_start_at_window_end_is_reported_and_retried (the start_cmd fails once, then works)

before:
E       AssertionError: 'service_restart' not found in ['service_stop', 'service_start']
after:
1 passed

Stop and withdraw waited up to 15 s holding the lock

What went wrong. stop_job sent SIGTERM, then polled for up to 15 s inside with self.lock, and remove_job held the lock around the whole stop. A request for a sleeping service, the tick, and other actions waited behind it.

Fix. stop_job takes the lock to send SIGTERM, waits without it, and takes it again for the SIGKILL, the exit check and the state change. remove_job calls stop_job first, outside the lock. The hold that stop_job writes to the queue file before it looks for processes keeps the scheduler from starting the job in between, so the 0.26.3 guarantee still holds: a job that starts at that moment is stopped, not lost.

Test. tests/test_stop_without_lock.py: the lock can be taken while a Stop waits on a job that ignores SIGTERM, a tick in between doesn't restart it, and it's still killed at 15 s. The same lock check runs for a withdraw.

before:
>       self.assertTrue(lock_free_while(r, t.is_alive))
E       AssertionError: False is not true      (both tests)
after:
2 passed

A revoked governor app was waited for up to timeout_s

What went wrong. GovernorJob.park waited up to timeout_s (120 s by default) for a revoked app to step aside. Parks started by the tick hold the transition lock for that whole wait.

Fix. The wait is now min(timeout_s, grace_s + 10). The launcher kills its command grace_s after a revoke, so an app still there 10 s later isn't stepping aside, and kill_stuck_jobs takes over as before. Apps that step aside within their grace period see no change. The grace_s row in docs/CONFIG.md says so. This covers governor jobs only. restart jobs on the tick path keep their full timeout_s, because a shorter cap could SIGKILL a job while it saves a checkpoint on SIGTERM.

Test. tests/test_governor.py::RevokeWaitTest::test_a_revoke_the_app_ignores_waits_its_grace_not_timeout_s (a granted app that never steps aside, with timeout_s = 30 and grace_s = 0.5). It runs without /proc, so it runs on macOS too.

before:
E       AssertionError: 30.057213249994675 not less than 11.5
after:
1 passed (10.6 s)

State files with the wrong shape

What went wrong. The readers handled missing files and invalid JSON, but not valid JSON of the wrong shape. A WINDOW file such as {"until": "06:00"}, or a list, made every tick fail, and every request that had to wake a sleeping service lost its connection with no answer. A wrong-shaped queue.json did the same. A wrong-shaped costs.json, gaps-<service>.json or submitted.json stopped the daemon from starting at all.

Fix. A WINDOW file that isn't a window counts as no window (never as an open-ended one), and the tick logs it once per version of the file as window_file_ignored. read_queue returns an empty queue unless it gets an object with a jobs list, and skips rows that aren't objects. CostBook and GapModel.load also catch AttributeError and TypeError. In Submissions.load, the per-row checks moved inside the per-row try.

Test. tests/test_bad_state_files.py

before:
E       AttributeError: 'list' object has no attribute 'get'
E       ValueError: could not convert string to float: '06:00'
E                   AttributeError: 'list' object has no attribute 'get'
3 failed
after:
3 passed

A job's own request could be parked under

What went wrong. After deciding to park, the tick re-checked only inflight. A job's own request (/_job/<name>/…) counts in job_inflight, so one that arrived between the snapshot and the park went ahead and the service was put to sleep under it.

Fix. The re-check is now if s["inflight"] or s["job_inflight"], as _switch already does.

Test. tests/test_job_request_park.py::test_a_job_request_after_the_snapshot_keeps_the_service_hot

before:
E       AssertionError: 'parked' != 'hot'
after:
1 passed

Queue file changes could overwrite each other

What went wrong. The page's actions, Stop, max_hours, a frozen job's step-aside and Jobs API submit and withdraw each read queue.json, changed it and wrote it back with no lock. Two at once lost one change. A lost Stop hold meant the job started again. They also shared one temp file, so one writer could fail with FileNotFoundError.

Fix. A separate queue_lock (an RLock) now covers each read-modify-write: the queue edits in ui.act, _set_hold, add_job and remove_job. Stop and max_hours now set their hold through _set_hold. The lock is only taken after Runner.lock, never before it, and page actions don't wait behind parks.

Test. tests/test_queue_writers.py::test_concurrent_queue_changes_are_all_kept: 200 page edits race 200 holds set by the runner. It failed on every run before the change.

before (3 runs):
E       AssertionError: Lists differ: [0] != []
E       AssertionError: Lists differ: [0, 1, 2, 3, ... 199] != []   (thread died: FileNotFoundError on queue.json.tmp)
E       AssertionError: Lists differ: [0] != []
after (5 runs):
1 passed  x5

The gate trusted Content-Length and had no timeout

What went wrong. A non-numeric Content-Length dropped the connection with no answer. -1 read until EOF and hung. There was no size limit, and a chunked body was read as the next request. Without a socket timeout, a silent client held a thread for good.

Fix. The gate answers 400 for a non-numeric length, 413 above 64 MiB and 411 for a body sent with Transfer-Encoding, and closes the connection in each case. These requests are never counted. Gate sockets get timeout = 60, like the UI's. The wait for the engine still uses request_timeout_s.

Test. tests/test_gate_request_body.py

before:
E       AssertionError: None != 400
E       AssertionError: None != 60
2 failed
after:
2 passed

Full suite

On macOS. The 17 skipped tests need Linux /proc, as on main.

python3 -m pytest -q                                  166 passed, 17 skipped
python3 -W ignore -m unittest discover -s tests       Ran 183 tests ... OK (skipped=17)

main had 152 passed and 17 skipped under pytest. This branch adds 14 tests. No live hardware tests were run for this PR.

A job added or withdrawn through the Jobs API while request_start looped over
the job table made it raise "dictionary changed size during iteration" after
it had counted the request. The gate called request_start outside its try, so
request_end never ran and the service's in-flight count stayed at 1 for good:
no parks, no gap jobs, paused yield jobs never resumed until a restart.

request_start, snapshot, status, _track_progress, _track_speed and sample now
loop over a copy of the job table, status skips a job withdrawn since its
snapshot, and the gate calls request_start inside the try whose finally runs
request_end.

Verified with tests/test_job_table_changes.py (three tests, all failing before
the change) and the full suite.
…rvice dead

When start_cmd failed as an exclusive window closed, the service was left
neither stopped, starting nor dead. Requests got no 503 explaining it, no gap
jobs were admitted, and the restart began only after the first real request
had failed a wake.

The failure branch now sets dead_since. Requests get a 503 saying the service
failed and is being restarted, and _recover (later in the same tick) runs
stop_cmd and start_cmd once. If that fails as well, the existing _recover
logic applies.

Verified with tests/test_window_start_fails.py (start_cmd fails once, then
works), which failed before the change, and the full suite.
stop_job sent SIGTERM and then waited up to 15 s for the job to exit while
holding the transition lock, and remove_job (Jobs API withdraw) held the lock
around the whole stop. A request for a sleeping service, the tick, and other
actions waited behind it; a job that saves a checkpoint on SIGTERM made that
wait as long as the save.

stop_job now takes the lock to send SIGTERM, waits without it, and takes it
again for the SIGKILL, the exit check and the state change. remove_job calls
stop_job first, outside the lock, and takes the lock only to forget the job.
The hold that stop_job writes to the queue file before it looks for processes
still keeps the scheduler from starting the job in between, so a job that
starts at that moment is stopped, not lost.

Verified with tests/test_stop_without_lock.py (the lock can be taken while a
Stop or a withdraw waits; a job that ignores SIGTERM is still killed at 15 s
and not started again by a tick in between), which failed before the change,
and the full suite.
GovernorJob.park waited up to the job's timeout_s (120 s by default) for a
revoked app to step aside. Parks started by the tick (idle release, the
scheduler, window end, recovery) hold the transition lock for that whole
wait, so a request for a sleeping service waited behind it.

The launcher kills its command grace_s after a revoke, so an app still there
10 s after that is not stepping aside. park now waits at most
min(timeout_s, grace_s + 10) and then fails as before, and kill_stuck_jobs
takes over. Apps that step aside within their grace period see no change.
The grace_s row in CONFIG.md says so.

Parks of other drivers on the tick path (restart jobs that ignore SIGTERM)
keep their timeout_s; capping those would SIGKILL a job saving a checkpoint.

Verified with RevokeWaitTest in tests/test_governor.py (a granted app that
never steps aside: park took 30 s with timeout_s = 30 before, 10.6 s now
with grace_s = 0.5), and the full suite.
The state-file readers handled a missing file and invalid JSON, but not valid
JSON of the wrong shape. A WINDOW file holding {"until": "06:00"} or a list
made every tick fail, and every request that had to wake a sleeping service
lost its connection with no answer. A queue.json that was a list or held
non-object rows did the same. A wrong-shaped costs.json, gaps-<service>.json
or submitted.json stopped GapRunner from starting at all.

- WINDOW: a file that isn't a window counts as no window (never an
  open-ended one), and the tick writes one window_file_ignored audit row per
  version of the file. CONFIG.md says so.
- queue.json: anything but an object with a "jobs" list is an empty queue;
  rows that aren't objects are skipped.
- costs.json and gaps-<service>.json: a wrong shape starts with no samples.
- submitted.json: a wrong shape loads no submissions; a row that isn't an
  object is dropped and logged like any other bad row.

Verified with tests/test_bad_state_files.py (tick, wake, request and status
with a bad WINDOW or queue.json; Runner start with each other file holding a
list or wrong-typed fields), which failed before the change, and the full
suite.
After deciding to park an idle service, the tick re-checked only ordinary
requests in flight. A job's own request (/_job/<name>/...) that arrived
between the tick's snapshot and the park saw the service hot, went ahead
without waiting, and the service was put to sleep under it.

The re-check now counts the job's requests too, as the engine switch already
does.

Verified with tests/test_job_request_park.py (a job request lands right after
the snapshot; the service stays hot), which failed before the change, and the
full suite.
The page's actions, Stop, max_hours, a frozen job's step-aside and Jobs API
submit and withdraw each read queue.json, changed it and wrote it back with
no lock between them. Two overlapping changes lost one of them; the worst
case was a page action overlapping a Stop, which lost the Stop's hold so the
scheduler started the job again. Two writers also shared one temporary file,
so one of them could fail outright with "No such file or directory".

A small queue_lock (separate from the transition lock, so page actions never
wait behind a park) now covers each read-modify-write: every queue edit in
ui.act, _set_hold, add_job and remove_job. Stop and max_hours now set their
hold through _set_hold instead of their own copies of the same code. The
lock is only ever taken after the transition lock, never before it.

Verified with tests/test_queue_writers.py (200 page edits racing 200 holds
set by the runner: all edits kept), which failed on every run before the
change, and the full suite.
The gate trusted Content-Length. A non-numeric value dropped the connection
with no answer; -1 read until the client closed, which hung while it kept the
connection open; there was no size limit; and a chunked body was ignored, so
its bytes were then read as the next request. The gate also had no socket
timeout, so a client that stopped sending held a thread for good.

The gate now answers 400 for a Content-Length that isn't a whole number, 413
above 64 MiB, and 411 for a body sent with Transfer-Encoding, and closes the
connection in each case. These requests are never counted as activity. Socket
reads and writes to the client time out after 60 s, as the web page's do;
the wait for the engine's answer still uses request_timeout_s.

Verified with tests/test_gate_request_body.py (raw requests with bad lengths
and a chunked body get their error at once; the handler sets a timeout),
which failed before the change, and the full suite.
Bumps the version in gaprunner/__init__.py and pyproject.toml and adds the
0.29.0 changelog entry for the fixes in this release.
Keep the dead marker if the recovery start command fails, and retry after dead_retry_s. Clear the marker when a later window start becomes ready.

Verified with tests/test_window_start_fails.py: the new repeated-failure regression failed with an absent 503 reason before the fix; both tests pass afterward.
Mark stopping and withdrawing jobs under the transition lock. Start may clear the queue hold, but scheduling and direct starts wait until Stop finishes; withdrawal stays protected until removal.

Replace real process delays with an event-controlled wait and simulated monotonic time. The two Start-during-wait cases failed before the fix; all four stop regressions now pass in 0.04 s.
Avoid looking up withdrawn entries after queue or process reads. Recheck a progress hook target under the transition lock before parking it. Count requests before activity writes so gate cleanup cannot drive inflight negative.

New regressions reproduced KeyError during withdrawal and inflight = -1 after a failed activity write. All 12 reader, progress and wind-down tests pass. Reader tests no longer race an unrelated background tick.
Reject invalid window end and exclusive values, queue names that are not strings, nonnumeric cost samples, and gap collections that are not lists. Preserve the existing empty-window and numeric timestamp formats.

New state-field tests failed with an unintended open-ended window and a median TypeError before the fix. All 17 malformed-state, measurement, and replay/config tests pass afterward.
Advance a driver-local fake clock instead of sleeping for grace_s + 10 s. Assert both the grace bound and a shorter timeout_s, including a lower bound so an immediate failure cannot pass.

The test fails against main at 30 simulated seconds and passes with the C4 fix in 0.02 s.
Bound numeric conversion, reject non-ASCII digits and duplicate or empty lengths, and reject truncated bodies. Apply framing checks to the state endpoint too. Verify socket timeouts with silent and partial-body clients.

The new malformed-length and truncated-body tests failed before the fix. All five gate-body tests pass afterward; the complete C1-C8 regression set also fails against an isolated main archive as expected.
Keep the event-controlled race tests and add a real process that installs SIGTERM ignore before Stop runs. Advance only the runner clock so SIGKILL and process discovery are still exercised without a 15 s delay.

Verified all five Stop regressions pass in 0.38 s, including a real -SIGKILL exit and an empty process list.
The recovery fix also uses dead_retry_s between failed start commands. Document that behavior alongside its existing wake retry meaning. Documentation only; checked against the recovery regression.
@benbuschmann
benbuschmann merged commit 3a5742b into main Oct 29, 2026
8 of 9 checks passed
@benbuschmann
benbuschmann deleted the audit-p1-p2 branch October 29, 2026 00:37
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant