Merge stream E (worker: cache eviction, ReadBulk shared deadline + dedupe, alarm poll threshold, STA loop fault, unhandled-exception hook, live control-command facts)

This commit is contained in:
Joseph Doherty
2026-10-22 08:28:55 -04:00
23 changed files with 2239 additions and 92 deletions
+81 -6
View File
@@ -133,6 +133,9 @@ starts the STA, or touches MXAccess:
| `2` | `InvalidArguments` | Required arguments are missing or unknown arguments are present. |
| `3` | `InvalidProtocolVersion` | `--protocol-version` is not numeric or does not match the supported worker protocol. |
| `4` | `MissingNonce` | `MXGATEWAY_WORKER_NONCE` is absent or empty. |
| `5` | `PipeConnectionFailed` | An `IOException` or `TimeoutException` escapes the pipe client. |
| `6` | `ProtocolViolation` | A `WorkerFrameProtocolException` escapes the pipe client. |
| `7` | `UnhandledException` | An exception reaches the `AppDomain.UnhandledException` hook (see `docs/WorkerBootstrap.md`). |
Bootstrap logs use `WorkerConsoleLogger` key/value output. `WorkerLogRedactor`
redacts fields whose names indicate nonce, secret, password, token,
@@ -270,12 +273,33 @@ is still responsive. Shutdown marks the runtime as closing, wakes the pump,
rejects new commands, cancels queued work, uninitializes COM on the STA, and
waits for the thread to exit.
`ProcessQueuedCommands` pumps pending Windows messages between queued work
items whenever more work remains, not only after the whole queue drains. A
burst of queued commands would otherwise hold every inbound COM callback
(`OnDataChange`, `OnWriteComplete`) behind the entire backlog.
If the STA loop itself throws after `Start` has returned (a failed
`MsgWaitForMultipleObjectsEx`, or an exception escaping a dispatched message),
`StaRuntime` records the exception as `LoopFault`, fails every later
`InvokeAsync` with an `InvalidOperationException` wrapping it (never the
graceful `StaRuntimeShutdownException`), cancels queued work, and invokes the
handler registered through `RegisterLoopFaultHandler` — unless a requested
shutdown is already in progress, in which case the death is part of a
deliberate teardown and is not reported. `MxAccessStaSession` registers a
handler that records a `StaHung` `WorkerFault` on the event queue (diagnostic
text carries the exception type and HRESULT only, never the message),
so the IPC drain loop sends the fault to the gateway and ends the pipe session
and the worker process. Before this, a post-start loop death was stored in the
startup-exception field that only `Start` reads, leaving a live worker whose
commands queued forever. Startup failures still surface from `Start` itself.
### Inner Completion Waits
Two commands hold the STA while waiting for a COM event they just provoked: the
unary write path waits for its `OnWriteComplete`
(`MxAccessWriteCompletionCache.TryWaitForCompletion`), and `ReadBulk` waits per
tag for the first `OnDataChange` (`MxAccessValueCache.TryWaitForUpdate`). Both
(`MxAccessWriteCompletionCache.TryWaitForCompletion`), and `ReadBulk` waits for
the first `OnDataChange` of every snapshot tag
(`MxAccessValueCache.TryWaitForUpdates`). Both
run the same loop shape as the outer pump, for the same reason — the event they
are waiting for *is* a Windows message, so the thread must keep dispatching to
receive it:
@@ -297,7 +321,7 @@ The idle slice is a Win32 wait (`StaWaitHelper.WaitForSignalOrMessages`), never
`Thread.Sleep`. A sleeping STA pumps no messages, so a sleep-polled loop could
only dispatch the awaited COM event at poll-tick granularity while stalling
*every other* event for the same tick — up to 1.5 s for a write completion and
up to `timeout_ms` per tag for `ReadBulk`. The Win32 wait returns the instant a
up to `timeout_ms` for `ReadBulk`. The Win32 wait returns the instant a
message needs pumping, so the apartment dispatches continuously for the whole
wait. Each cache also sets an `AutoResetEvent` from its update path (outside the
cache lock) so a cross-thread producer wakes the waiter immediately; in the live
@@ -317,8 +341,29 @@ nothing wakes the wait — a process with no STA message queue (unit tests drive
these caches from ordinary threads, standing in for the STA by updating the
cache from a fake `pumpStep`) must not block for a full poll interval. Timeouts,
deadline math, and return values are unchanged by the wait mechanism: an expired
write wait still yields the empty-`statuses` unconfirmed reply, and an expired
per-tag `ReadBulk` wait still reports its own timeout.
write wait still yields the empty-`statuses` unconfirmed reply, and every
`ReadBulk` tag that did not deliver before the deadline still reports its own
timeout.
`ReadBulk` runs its snapshot lifecycle in phases so the STA is held for at most
one `timeout_ms` per command, not one per tag: (1) every tag is validated and
probed against the cached-and-advised fast path; (2) every remaining tag is
added and advised; (3) one wait with a shared deadline collects the first
`OnDataChange` per snapshot handle and returns as soon as all have delivered;
(4) every snapshot handle is unadvised and removed, best-effort. Per-tag
results are unchanged: request order, the blank-address failure, the cached
result, an `AddItem` failure (item handle 0) or `Advise` failure (its own item
handle) failing only that tag, and the `ReadBulk timed out after <n> ms waiting
for first OnDataChange.` message for each tag that never delivered. The cache
probes all run before any snapshot `AddItem`, so a later tag in the same
request can never be served from an earlier tag's snapshot subscription.
When MXAccess returns the same item handle for two tags in one batch (a
duplicate address), the handle is advised, unadvised, and removed once, and
every duplicate receives the shared outcome. Phases 2 and 4 make one or two
COM calls per tag without waiting, so they call the pump step every
`ReadBulkPumpInterval` (16) tags; a large batch therefore keeps dispatching
inbound callbacks and refreshing `LastStaActivityUtc` instead of drifting
toward `HeartbeatStuckCeiling`.
The write wait's budget is `MxGateway:Worker:WriteCompletionWaitMilliseconds`
(default 1500). It applies to `Write`, `Write2`, `WriteSecured`, and
@@ -671,7 +716,20 @@ The worker records plain and supervisory advice separately only after the COM
call returns normally. Successful `UnAdvise` removes all tracked advice for the
server and item pair because the public MXAccess cleanup method has no plain
versus supervisory selector. Successful `RemoveItem` and `Unregister` also clear
related advice state from the worker registry. Failed advice and cleanup calls
related advice state from the worker registry, and evict the per-handle
caches the event sink fills: `RemoveItem` drops the handle pair's
`MxAccessValueCache` and `MxAccessWriteCompletionCache` entries, and
`Unregister` drops every entry recorded under the server handle (MXAccess
removes the server's items with it, so the per-item eviction never runs for
them). Without this, an `AddItem` → `Write` → `RemoveItem` churn grew the
completion cache by one entry per cycle for the life of the worker.
`AddItem`, `AddItem2`, and `AddBufferedItem` also drop both cache entries for
the handle they receive when the registry does not already track it. An
`OnDataChange` or `OnWriteComplete` that was queued when `RemoveItem` or
`Unregister` ran is dispatched after the eviction and recreates the entry;
when MXAccess later reuses that item id, `ReadBulk`'s cached path would
otherwise serve the stale value as `was_cached = true`. A handle the
registry still tracks belongs to a live item, so its entries are kept. Failed advice and cleanup calls
leave registry state unchanged so diagnostics continue to reflect the last
successful MXAccess-owned state transition.
@@ -905,6 +963,23 @@ the STA more than 75 s without pumping *should* fault — that is the ceiling's
contract). The flag is named generically so any future non-dispatcher STA work
reuses it.
A `PollOnce` that throws does not fault the session on the first failure. The
poll loop counts consecutive failures and records the alarm-poll fault
(`MxaccessEventConversionFailed`) only when the count reaches
`MxAccessStaSession.DefaultAlarmPollFailureThreshold` (3, the same default as
`AlarmFailoverConfig.consecutive_failure_threshold`); a successful poll resets
the count. Each failure below the threshold writes one
`level=Warning event=AlarmPollFailed` line to stderr carrying the exception
type, HRESULT, and counts only — the exception message is left out because it
can echo alarm or tag names. A single transient COM failure in
`GetXmlCurrentAlarms2` used to fault the whole session, taking every data
subscription with it; a persistent failure, including an STA-affinity
regression that fails every tick, still faults within three poll intervals.
A poll failure seen after the STA loop itself has died (`StaRuntime.LoopFault`
is set) ends the poll loop without recording anything: the loop-fault handler
has already recorded the `StaHung` fault, and the failure is only the
fast-fail `InvokeAsync` returns afterwards.
The in-flight-command suppression itself is bounded by
`WorkerPipeSessionOptions.HeartbeatStuckCeiling` (default 75 seconds = 5 ×
`HeartbeatGrace`). The motivating case for the suppression is a legitimately