Commit Graph

5 Commits

Author SHA1 Message Date
Joseph Doherty 5962cc3d41 docs(scripting): T starts at the run's start but is wall clock from there; document the late-notice, ceiling and counter rules (#827 review F4)
The proto comment, VirtualTags.md and CLAUDE.md said the soft deadline
measures the script's own execution and that starvation never counts. Only
the time before the run STARTS is excluded; from the start it is wall-clock
time, as in process, so a GC pause or a starved / suspended worker during
the run still counts. A mid-run freeze test is not added: it races the
script's own return against the watchdog's notice; documented as not covered.
Also documents F2 (late notice cancels and counts), F3 (progress ceiling,
killed_unresponsive) and F5 (answer = stalled | retrigger).
2026-11-11 02:26:28 -05:00
Joseph Doherty f50209082e fix(scripting): count re-triggers answered 'worker unresponsive' (#827 review F5)
otopcua.script.ipc.timeouts gains the tag answer = stalled | retrigger: a
later trigger refused while the key's stalled run is still unanswered was
counted nowhere (not a script refusal, so not ScriptRunGuard's counter).
KeyState carries its Kind for the tag. Test: the stalled-worker test listens
for the instrument and sees one stalled and one retrigger (before: only
stalled).
2026-11-11 02:25:17 -05:00
Joseph Doherty 3f5fdd1d90 fix(scripting): host progress ceiling kills a worker that heartbeats but never answers (#827 review F3)
With the worker soft clock the host's per-run timer is only the transport
deadline and the kill G is armed by the worker's soft notice, so a worker
whose watchdog never sends one (the design treats the worker as untrusted)
held the run, the key's slot and the tag's BadResourceUnavailable forever;
a deferred run had no host clock at all.

WorkerConnection now tracks evaluation progress (any Results frame, or the
submit that made the worker busy again). The heartbeat monitor kills the
worker when evaluations are outstanding and nothing progressed for
3 x the largest outstanding T + G plus the silence limit:
WorkerExitReason.KilledUnresponsive (metric reason killed_unresponsive), no
culprit, attributed like a heartbeat kill (suspects, no strike on a shard).
A legitimate run has answered or been killed by T + G.

Test seams: ProgressCeilingOverride, DropSoftNoticesForTest. Tests: a worker
whose notices are dropped (G = 60 s, so its own fail-fast cannot end it) is
killed KilledUnresponsive after the 1.5 s ceiling and the run is released
(with the check disabled the test times out); positive control: 20 queued
150 ms runs behind one thread under a 1 s ceiling are all answered.
2026-11-11 02:24:01 -05:00
Joseph Doherty c5dffbd8b8 fix(scripting): soft notice resumes the caller on the dispatcher; a late notice still cancels and counts (#827 review F1, F2)
F1: PendingEval.SoftExpired runs on the pipe reader and completed the
caller's outcome inline (production outcomes have no async continuations, by
design, because results resume on the ResultDispatcher). The caller's code
(the runner's Cancel write, the seam's publish) therefore ran on the reader,
which could hold up heartbeats (a false silence kill) and, with blocking I/O,
write to the pipe from the reader. The soft outcome is now posted to the
dispatcher like a result. Test: a 1.5 s continuation on a soft timeout with a
300 ms silence limit resumes on ScriptWorker[t].Results and the worker lives
(before: it resumed on the Reader).

F2: after a transport timeout ("worker unresponsive"), a late soft notice
armed G but nobody sent Cancel, so a polling script could not end itself and
the whole worker was killed at notice + G with a kill strike. PendingEval now
exposes LateSoftExpiry (asynchronous continuations, cancelled when the run
answers); the runner sends the Cancel and counts the timeout
(NoteTimeout) from it. A genuinely slow script whose notice is delayed past
T + G is thus still a timeout. Test: stall past T + G, thaw, a polling
script overruns T: the worker survives G and the key is quarantined for
timeouts, not a hard deadline (before: the worker was killed).
2026-11-11 02:21:45 -05:00
Joseph Doherty f7ca2c5826 fix(scripting): out-of-process soft deadline measures the script's own run, not the pipe or a starved worker (#827)
The soft deadline T was armed on the host at submit, so the pipe round trip
and the time a starved worker waits to be scheduled counted against the
script: under load a trivial script reported 'script timed out', in Shadow
mode that was a script mismatch, and at T + G the host killed the worker and
struck the key.

- Protocol (additive, negotiated): Hello/Ready.worker_soft_clock and
  EvalResults.soft_expired_eval_ids. protocol_version stays 1; a worker that
  does not echo the flag keeps the pre-#827 host clock.
- Worker: the watchdog runs each run's soft clock from the moment an
  evaluation thread starts it and reports the crossing (woken early for
  budgets shorter than its 50 ms poll). It still never cancels by itself;
  its fail-fast is anchored at the soft notice + G + margin.
- Host (PendingEval): the soft notice answers the caller and arms the kill G
  later. The host's own timer becomes a transport deadline, T + G from submit
  (restarted at a deferred run's start); passing it with no result and no
  notice yields TransportTimedOut -> Unavailable 'script worker unresponsive'
  (BadResourceUnavailable, recovery = the run's completion), no strike, no
  kill, no Cancel. A re-trigger refused by that still-unanswered run is
  Unavailable too, not 'previous run still running'. Counted as
  otopcua.script.ipc.timeouts{kind}.
- Frame writer: coalescing now carries soft_expired_eval_ids (it silently
  dropped them); the host processes soft notices before results in a frame.
- Shadow: unresponsive is shadow_unavailable (Unavailable), never a mismatch.

Tests: WorkerSoftClockTests suspends the real worker (SIGSTOP via libc kill /
NtSuspendProcess) - a stall past T still returns 7; a stall past T + G is a
runner fault with nothing struck; a late-starting runaway is still timed out
at T from its start and killed G after; Shadow stays match /
shadow_unavailable; both clocks enforce T and G; PendingEval state machine.
2026-11-11 01:38:46 -05:00