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
parent f50209082e
commit 5962cc3d41
5 changed files with 40 additions and 26 deletions
@@ -395,7 +395,7 @@ lists `ScriptedAlarm` — never by default) in `ZB.MOM.WW.OtOpcUa.ScriptWorker`
 (`src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.OutOfProcess`, protocol in `Core.Scripting.Protocol`), shipped in `script-worker/`
 beside the host (self-contained + started via its apphost on a `-r win-x64 --self-contained` publish, through the muxer otherwise); a runner-side failure publishes `BadResourceUnavailable` (ScadaBridge-visible, ScadaBridge#112) and the seam re-evaluates
 when the worker is back. `IScriptRunner.RunBatch` sends ready evaluations as one frame per worker (Calc pump, VT coalescer,
-alarm dirty set); a run queued behind busy worker threads has its deadlines restarted when it starts, so it is never blamed for a sibling. The soft deadline is the **worker's** clock from the run's start (#827, negotiated via `Hello`/`Ready.worker_soft_clock`); the host only keeps a T + G transport deadline, and passing it is a runner fault (`script worker unresponsive` → `BadResourceUnavailable`, Shadow `shadow_unavailable`), never a script timeout. Optional `Scripting:Worker:PeCacheDir` = HMAC'd compiled-PE cache (restart without Roslyn); optional (Windows) `Scripting:Worker:Identity` = `NT SERVICE\OtOpcUaScriptWorker` runs workers under a restricted token, set up by `scripts/install/Install-ScriptWorkerIsolation.ps1` (ACLs + outbound firewall block; `docs/ServiceHosting.md`); the `script-runner`
+alarm dirty set); a run queued behind busy worker threads has its deadlines restarted when it starts, so it is never blamed for a sibling. The soft deadline is the **worker's** clock from the run's start (#827, negotiated via `Hello`/`Ready.worker_soft_clock`); wall clock from there, so a pause during the run still counts. The host keeps a T + G transport deadline (passing it is a runner fault: `script worker unresponsive` → `BadResourceUnavailable`, Shadow `shadow_unavailable`; a later soft notice still cancels and counts the timeout) and a progress ceiling (`killed_unresponsive`) so it never depends on the worker's notices. Optional `Scripting:Worker:PeCacheDir` = HMAC'd compiled-PE cache (restart without Roslyn); optional (Windows) `Scripting:Worker:Identity` = `NT SERVICE\OtOpcUaScriptWorker` runs workers under a restricted token, set up by `scripts/install/Install-ScriptWorkerIsolation.ps1` (ACLs + outbound firewall block; `docs/ServiceHosting.md`); the `script-runner`
 readiness check is at worst Degraded (never fails ready). The worker tests
 are `tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests` (`Category=ScriptWorker`, real processes; `Category=Perf` harness opt-in via
 `OTOPCUA_SCRIPT_PERF=1`). docker-dev overlay: `docker-dev/docker-compose.script-runner.yml`. See `docs/VirtualTags.md`
@@ -58,18 +58,27 @@ processes:
  `script timed out after …` failure and the run token is cancelled inside the worker; at `T + G`
  (`Scripting:Worker:HardGrace`, default `max(1 s, T)`) the worker is **killed** (`Process.Kill(entireProcessTree)`,
  plus a worker-side fail-fast watchdog) — the thread, its memory and its ALC go with it.
- **`T` is the script's own run time (lmxopcua#827).** As in process (where the guard's clock starts when the
-  thread pool picks the run up), `T` starts when a worker evaluation thread starts the run — not at submit — so the
-  pipe round trip and the time a starved worker waits to be scheduled never count against the script. The worker runs
-  that clock and reports the crossing (`EvalResults.soft_expired_eval_ids`); the host answers its caller, sends the
-  cancel, and arms the kill `G` after the notice. What the host still times on its own is a **transport deadline**,
-  `T + G` from submit (restarted at a queued run's start): no result and no soft notice by then is the runner's fault —
-  the tag publishes **`BadResourceUnavailable`** (`"script worker unresponsive"`), nothing is struck or quarantined,
-  the worker is not killed (a really hung one goes silent and the heartbeat monitor kills it), and the seam
-  re-evaluates when the worker answers. A re-trigger while that run is still unanswered is the runner's fault too, not
-  `previous run still running`. Counted as `otopcua.script.ipc.timeouts{kind}`. The clock is negotiated in the handshake
-  (`Hello`/`Ready.worker_soft_clock`): a worker that does not echo it keeps the host clock from submit (the pre-#827
-  contract), so a mismatched host/worker pair degrades to the old behaviour instead of losing its deadlines.
+- **`T` starts when the run starts (lmxopcua#827).** As in process (where the guard's clock starts when the thread
+  pool picks the run up), `T` starts when a worker evaluation thread starts the run — not at submit — so the pipe
+  round trip and the time a starved worker takes to **start** the run never count against the script. From the start
+  on it is wall-clock time, exactly as in process: a GC pause, a CPU-starved or suspended worker **during** the run
+  still counts against `T` (not separated, and not tested beyond that equivalence). The worker runs that clock and
+  reports the crossing (`EvalResults.soft_expired_eval_ids`); the host resumes its caller on the result dispatcher
+  (never on the pipe reader), sends the cancel, and arms the kill `G` after the notice.
+  - **Transport deadline.** What the host still times on its own is `T + G` from submit (restarted at a queued run's
+    start): no result and no soft notice by then is the runner's fault — the tag publishes **`BadResourceUnavailable`**
+    (`"script worker unresponsive"`), nothing is struck, the worker is not killed, and the seam re-evaluates when the
+    worker answers. A re-trigger while that run is still unanswered gets the same answer, not
+    `previous run still running`. If the worker then reports the script over `T` after all (slow **and** late — a
+    notice delayed past `T + G` lands here too), the run still gets its cancel and counts as a timeout. Counted as
+    `otopcua.script.ipc.timeouts{kind, answer = stalled | retrigger}`.
+  - **Progress ceiling.** The host does not depend on the worker's notices to end a run: while evaluations are
+    outstanding, a worker that keeps heartbeating but produces no result, start or soft notice for
+    `3 × the largest outstanding T + G + 3 heartbeat intervals` is killed (`killed_unresponsive`, no culprit,
+    attributed like a heartbeat kill). A worker that stops heartbeating is killed by the silence rule as before.
+  - **Negotiated.** The clock is agreed in the handshake (`Hello`/`Ready.worker_soft_clock`): a worker that does not
+    echo it keeps the host clock from submit (the pre-#827 contract), so a mismatched host/worker pair degrades to the
+    old behaviour instead of losing its deadlines.
 - **Attribution and quarantine** live in the host and survive restarts: a deadline kill strikes exactly its key
  (other evaluations in flight are victims, not strikes); a crash with no deadline crossed makes every key in flight
  a suspect that must complete `Scripting:Worker:IsolationProbationRuns` (20) clean runs in the isolation worker,
@@ -204,8 +204,9 @@ internal sealed class WorkerConnection : IAsyncDisposable

    /// <summary>
    ///     lmxopcua#827: the worker runs each evaluation's soft clock from the moment an evaluation thread starts it and
-    ///     reports the crossing, so the soft deadline measures the script's own execution — not the pipe, not the time
-    ///     a starved worker takes to be scheduled. The host keeps a transport deadline of its own instead (see
+    ///     reports the crossing, so the soft deadline no longer counts the pipe or the time a starved worker takes to
+    ///     START the run. From the start it is wall-clock time, as in process: a pause during the run still counts. The
+    ///     host keeps a transport deadline of its own instead (see
    ///     <see cref="PendingEval"/>). Negotiated: asked for in <c>Hello</c>, true only when the worker echoed it in
    ///     <c>Ready</c>; otherwise the host's clock, started at submit, is the soft deadline (the pre-#827 contract).
    /// </summary>
@@ -147,14 +147,17 @@ message EvalResult {
 // just finished. So a run waiting behind a sibling is never timed out, struck or killed for the sibling's time.
 // Either list may be the only content of a frame. A host that predates these fields ignores them.
 //
-// Worker soft clock (lmxopcua#827, negotiated by Hello/Ready.worker_soft_clock): the soft deadline T measures the
-// script's OWN execution — the worker starts it when an evaluation thread starts the run and reports the crossing in
-// `soft_expired_eval_ids` (it does not cancel the run itself: the host answers its caller first, then sends Cancel,
-// keeping the in-process ordering). The host arms the hard deadline G from that notice. What the host keeps on its own
-// clock is a TRANSPORT deadline, T + G from submit (restarted at a deferred run's start): no result and no soft notice
-// by then means the pipe or the worker process is late — the caller is answered as a runner fault ("script worker
-// unresponsive", BadResourceUnavailable), never as a script timeout, and nothing is struck. A starved or stalled worker
-// therefore cannot make a trivial script look over budget; a hung one is still caught by the heartbeat silence kill.
+// Worker soft clock (lmxopcua#827, negotiated by Hello/Ready.worker_soft_clock): the soft deadline T starts when an
+// evaluation thread starts the run (not at submit) and is wall-clock time from there, as in process — a pause or
+// starvation DURING the run still counts. The worker reports the crossing in `soft_expired_eval_ids` (it does not
+// cancel the run itself: the host answers its caller first, then sends Cancel, keeping the in-process ordering). The
+// host arms the hard deadline G from that notice. What the host keeps on its own clock is a TRANSPORT deadline, T + G
+// from submit (restarted at a deferred run's start): no result and no soft notice by then means the pipe or the worker
+// process is late — the caller is answered as a runner fault ("script worker unresponsive", BadResourceUnavailable),
+// not as a script timeout, and nothing is struck (a soft notice that arrives later still cancels the run and counts as
+// a timeout). A worker that starts runs late therefore cannot make a trivial script look over budget; one that stops
+// heartbeating is killed for silence, and one that heartbeats without progress is killed at the host's progress
+// ceiling.
 message EvalResults {
  repeated EvalResult items = 1;
  repeated uint64 started_eval_ids = 2;
@@ -12,9 +12,10 @@ using ZB.MOM.WW.OtOpcUa.Core.Scripting.Protocol.V1;
 namespace ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests;

 /// <summary>
-///     lmxopcua#827: the soft deadline T measures the script's OWN execution — the worker runs it from the moment an
-///     evaluation thread starts the run — so the pipe round trip and the time a starved worker waits to be scheduled
-///     no longer count against the script. The host keeps a transport deadline (T + G from submit) and reports passing
+///     lmxopcua#827: the soft deadline T starts when an evaluation thread starts the run — the worker runs that clock —
+///     so the pipe round trip and the time a starved worker takes to START the run no longer count against the script.
+///     From the start it is wall-clock time, as in process: a pause DURING the run still counts, and is not tested
+///     here (a mid-run freeze races the script's own return against the watchdog's notice). The host keeps a transport deadline (T + G from submit) and reports passing
 ///     it as a runner fault (<see cref="ScriptRunOutcome.WorkerUnresponsiveReason"/>, BadResourceUnavailable), never as a
 ///     script timeout. The starved worker is made real here: its process is suspended (SIGSTOP / NtSuspendProcess)
 ///     while a trivial script is submitted.