scheduler: correctness and robustness fixes from two live nights

[wschoenell]

Scheduler fixes found operating the LNA 0.4 m robotically across 2026-07-21/22. All are reachable on current master; every fix carries a test verified to fail without it.

Commit 1 — alt/az pointing, lost START, duplicate runs

point with alt/az always crashed. Position.alt/az are floats (Coord.deg) while .ra/.dec are Coords; .to_d() on all four raised 'float' object has no attribute 'to_d' on every alt/az point (chimera-robobs parks with one, so it failed whenever its queue emptied).

A --start during executor.stop() was discarded by the unconditional state(OFF) after the blocking stop.

The same program could run several times concurrently. START overwrites BUSY; the machine re-entered IDLE, next(scheduler) returned the same unfinished program, and _process forked another thread — five concurrent autofocus runs and four concurrent sky flats on one camera, presenting as an endless focus loop.

Commit 2 — worker exit, cancellable waits, bounded abort, time order

Lost wakeup: the duplicate guard slept on the condition variable, but the worker signals IDLE from inside itself just before exiting — the wakeup was consumed before the sleep and the machine parked forever. It now polls the worker (join(1.0)).

Frozen state machine during aborts: executor.stop() blocks until the running action gives up (280 s observed for a camera readout) and ran on the machine thread. The abort now runs on its own thread bounded by STOP_ABORT_TIMEOUT (30 s); the abort itself continues in the background.

Uninterruptible pre-slew waits: a program waiting for a future start_at sat in time.sleep(); --stop could not reach it (no current action to abort) — a focus queued for 07:50 held the machine 90 minutes. The wait is now a cancellable event; STOP/SHUTDOWN release it and the program completes ABORTED.

Priority-only ordering starved the night: SequentialScheduler ordered by desc(priority) with no regard for start_at, so a high-priority program timed for dawn was picked at 22:00 and waited 10 h with the whole night queued behind it. Execution now follows start_at (priority breaks ties); programs without start times keep the old ordering.

Inline tracking stop (stop_tracking_on_program_end, default on): stopping tracking at program end used to live in the robobs plugin on a detached thread; stop_tracking() is locked, so the stale stop queued behind the next program's slew and untracked the freshly acquired target (TheSkyX re-enables tracking at slew end). It now runs inline on the program thread, ordered before the next program can start.

Tests

tests/chimera/controllers/ — one test per fix; each was checked against a reverted copy of its own source file. Notable reproductions: program forked 6 concurrent executions, machine parked after the worker exited, the START was not acted on during the abort, morning runs blockid 2 before 1.

Known limitation

STOP_ABORT_TIMEOUT bounds how long the machine is deaf during an abort, but after the timeout the machine reports OFF while the abort still runs — an honest STOPPING state is follow-up work. Resolved by the 2026-07-25 update below.

Update 2026-07-23: adds the stale-queue-entry fix from the third live night: reschedule() re-enqueues the currently RUNNING program (its finished flag is only written at completion), and the pop replayed it once it finished — a focus ran twice back to back. next() now re-checks each popped entry against the database and the worker commits the finished flag before the IDLE transition.

Update 2026-07-23 (2): a program past its valid_for window was reported complete ("not valid anymore") and then executed anyway — program_begin fired, the actions ran, and a second contradictory program_complete landed at the end (robobs advances its queue on the first one). The expired program is now finished without executing; programs with valid_for < 0 keep running late as before. Test: test_scheduler_expired_program.py, verified to fail without the fix.

Update 2026-07-25 — OFF only when the worker is dead. A live escalation on the fourth night (three stops survived, 154 dark frames on a closed dome over 52 min) showed the remaining gap: OFF was still declared with the worker alive, and when the surviving program finally died with an error its completion path flipped the stopped machine back to IDLE, re-arming the night. This update replaces the STOP_ABORT_TIMEOUT give-up with the honest STOPPING state: STOP aborts off-thread, joins the worker with a heartbeat log line, and only then reports OFF; terminal transitions from the worker are compare-and-set on BUSY, so a program's own completion or error can never re-arm a stopped machine. executor.stop() now sets must_stop even between actions and execute() clears its current handler on exit (a later stop cannot abort an action of a finished program); SequentialScheduler.done() survives the queue being rebuilt underneath it. Tests: an end-to-end rig (real bus, fake camera) replaying the incident sequence — start, re-start during BUSY, stop — asserting the camera stops and stays stopped after OFF, plus unit tests for worker-death-gated OFF and the sticky transition. The suite's scheduler database is now redirected to a temp file at conftest import (the model engine binds at import time; a full-suite run used to write into the user's real ~/.chimera/scheduler.db).

Update 2026-07-28 — a deleted program row must not kill the program thread. Aborting a program whose row was deleted while it ran killed the scheduler-program thread, and with it the completion event the rest of the stack waits for:

machine.py:293  log.debug(f"[aborted by user] {str(task)}")
ObjectDeletedError: Instance '<Program ...>' has been deleted

The abort itself completed correctly; the casualty was the logging. session.commit() expires every instance, so str(task) after it reloads the row — and the row is routinely gone by then: robobs cleans the chimera queue on start and on stop, and a replan rebuilds it. Every operator lock during a program hit this on opd-40 2026-07-28 (the abort landed 391 s after the delete, so it is not a tight race). Three defences: Program.__str__ falls back to the ORM identity instead of raising (a __str__ that can raise is a trap wherever it is used, and every scheduler log line formats a task); the program is described once, up front, while its row is certainly there; and the terminal bookkeeping is wrapped so a failure to record the end of a program cannot cost the completion event or the state transition. Test: test_scheduler_deleted_program.py (both halves verified to fail without the fix). The robobs-side half — the queue clean no longer deletes the row of the program the scheduler is executing — is in astroufsc/chimera-robobs#3.

Two smaller items from the same nights, in a second commit:

• Heartbeat. The machine waited in silence while a program ran (BUSY sleeps on the wake-up Condition; a worker counting down to its slew time or running a 10 min autofocus prints nothing), and twice that silence was diagnosed as "the scheduler is wedged" from the log alone. It now reports what it is running, for how long, and what it is waiting for, once a minute. The BUSY wait is bounded to make room for it; the Condition is still notified on every state change, so a STOP lands as immediately as before.
• File order for untimed queues. A hand-written chimera-sched --new queue (no start_at, one priority) ran in whatever order the database returned — in practice the reverse of the YAML. Insertion order is now the last tie-break.

[codecov]

Codecov Report

❌ Patch coverage is 80.51948% with 30 lines in your changes missing coverage. Please review.
✅ Project coverage is 54.48%. Comparing base (5599e42) to head (1c5b2c9).

Files with missing lines	Patch %	Lines
src/chimera/controllers/scheduler/machine.py	78.57%	21 Missing and 3 partials ⚠️
src/chimera/controllers/scheduler/executor.py	76.92%	4 Missing and 2 partials ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master     #255      +/-   ##
==========================================
+ Coverage   51.99%   54.48%   +2.48%     
==========================================
  Files         102      102              
  Lines        8626     8720      +94     
  Branches      999     1008       +9     
==========================================
+ Hits         4485     4751     +266     
+ Misses       3933     3737     -196     
- Partials      208      232      +24     

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.