Files
lmxopcua/archreview/plans/artifacts/456-retry-breaker-live-finding-2026-07-15.md
Joseph Doherty 5da7ba6517
v2-ci / build (pull_request) Successful in 4m29s
v2-ci / unit-tests (pull_request) Failing after 10m15s
docs(#456): live grind finding — write-trigger structurally impossible
Ran the full item-1 grind (authored a live Modbus equipment tag, connected
to the sim, LDAP-authed writes, docker pause the peer). 4 failing wrapped
writes produced 0 retry/breaker lines on either central.

Root cause (corrects the issue's hypothesis): ModbusDriver.WriteAsync swallows
all exceptions and returns WriteResult(StatusBadInternalError) — never throws;
CapabilityInvoker feeds only exceptions to Polly; breaker ShouldHandle is
Handle<Exception>; Write retry pinned to 0 (R2-02/S-8). So a failing wrapped
write emits no line by construction, for any polling driver. The line is
reachable ONLY for a session driver (OpcUaClient) faulting mid-Discover/Subscribe
(30s Polly timeout throws) — a production timing race, not deterministically
forcible on the rig. Behaviour stays unit-proven by the pipeline-builder test.

- New: archreview/plans/artifacts/456-retry-breaker-live-finding-2026-07-15.md
- FOLLOWUP-10 updated with the structural finding + recommendation to close item 1.
2026-07-15 14:48:03 -04:00

84 lines
6.4 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# #456 item 1 — live retry/breaker log-line capture: structural finding (2026-07-15)
**Outcome:** the log line was **not** captured, but the "grind" produced a **definitive structural
finding** that supersedes the issue's acceptance framing: the trigger the issue proposes (an idempotent
`WriteAsync` to a dead endpoint) is **structurally incapable** of emitting a retry/breaker line, and the line
is reachable in production **only** for a session-based driver (OpcUaClient) faulting *mid-`Discover`/`Subscribe`*
— a racy transient that cannot be deterministically forced on the dev rig. This is why three sessions with
polling-driver fixtures never observed it.
## What was actually driven live (the grind)
Full end-to-end wrapped-dispatch exercise on the docker-dev central cluster (`central-1`/`central-2`, MAIN):
1. Brought up the modbus sim on the shared host (`10.100.0.35:5020`, `otopcua-pymodbus-standard`).
2. **Authored a complete Modbus equipment hierarchy via SQL** (MAIN cluster): Equipment-kind `Namespace`
`ns-mb-eq``DriverInstance drv-mb` (`Modbus`, `{"Host":"10.100.0.35","Port":5020,"UnitId":1}`) → `Device`
`UnsArea`/`UnsLine``Equipment EQ-111111111111` → writable `Tag reg1`
(`{"region":"HoldingRegisters","address":1,"dataType":"Int16","byteOrder":"BigEndian","writable":true}`,
`AccessLevel=ReadWrite`, `WriteIdempotent=1`).
3. Deployed headless (`POST :9200/api/deployments`). Runtime log: `spawned Modbus driver drv-mb`
`DriverInstance drv-mb: connected``subscribed to 1 refs`. Node materialized at
`ns=2;s=EQ-111111111111/reg1`.
4. **Baseline (sim up):** live read `Good` (value 1); LDAP-authed (`multi-role`, `WriteOperate` role via the
shared GLAuth data-plane `GroupToRole`) write `= 123``Write successful`. **The wrapped write path is
fully live end-to-end** (OPC UA write → `NodeWriteRouter``DriverHostActor.RouteNodeWrite`
`DriverInstanceActor.WriteAsync` invoker-wrapped site → `ModbusDriver` → sim).
5. **Fault:** `docker pause otopcua-pymodbus-standard` (frozen peer — driver stays `Connected`), then drove 4
LDAP-authed writes into the frozen peer.
6. **Result:** every write logged `Operator write to EQ-111111111111/reg1 rejected: StatusCode=0x80020000`
(BadInternalError), node reverted. **`grep "Driver resilience retry|circuit-breaker OPENED"` on BOTH
centrals = 0 matches** despite 4 exercised, failing wrapped writes.
## Why the write trigger is structurally impossible
- **`ModbusDriver.WriteAsync` swallows every exception and returns a bad `WriteResult` status — it never
throws** (`ModbusDriver.cs:964-967`: `catch (Exception) { results[i] = new WriteResult(StatusBadInternalError); }`
`0x80020000`, exactly the observed reject status).
- **The `CapabilityInvoker` only feeds *exceptions* to the Polly pipeline** (`CapabilityInvoker.cs:84/112/147`:
`await pipeline.ExecuteAsync(callSite, …)` — the `callSite` is the driver's `WriteAsync`; a non-throwing
return is a pipeline **success**). The invoker does **not** inspect the returned `WriteResult` status.
- The circuit breaker's `ShouldHandle` is `Handle<Exception>` (`DriverResiliencePipelineBuilder.cs`), and
`Write` retry is **pinned to 0** as an invariant (R2-02/S-8, `DriverResilienceOptions.cs:64-66`).
- ∴ a failing wrapped **write** produces **no exception → no retry, no breaker count, no log line** — by
construction, for **any** driver that maps write failures to a status (all polling drivers do). The issue's
hypothesis ("the only invoker-wrapped Modbus site that throws is an idempotent `WriteAsync` to a dead
endpoint") is **incorrect** — even an idempotent write to a truly dead endpoint returns
`StatusBadInternalError` rather than throwing.
## Where the line IS reachable (and why it's elusive)
The retry/breaker pipeline fires only when a **wrapped capability call throws**. Of the 6 wrapped sites in
`DriverInstanceActor` (`Write`, `Acknowledge`, `Subscribe`, `Unsubscribe`, `SubscribeAlarms`, `Discover`):
- **Polling drivers (Modbus/S7/AbCip/AbLegacy/TwinCAT/Focas):** `WriteAsync`/`AcknowledgeAsync` swallow →
status; `SubscribeAsync` is a lazy poll-registration (no connect, no throw); `DiscoverAsync` is
offline/config-driven (enumerates authored tags, no connect). **None of their wrapped sites throw a
transient exception through the seam.**
- **Session drivers (OpcUaClient):** `DiscoverAsync` (remote browse) and `SubscribeAsync`
(CreateSubscription/CreateMonitoredItems) require a live session and **do** throw on a session fault. The
post-connect discovery loop (`DriverInstanceActor.StartDiscovery`, honouring `RediscoverPolicy`) runs
`DiscoverAsync` under a 30 s Polly timeout on each `Connected` entry.
So the **only** way to emit the line is a session driver whose session faults **while a wrapped
`Discover`/`Subscribe` is in flight** (e.g. `docker pause` of a live OPC UA endpoint mid-discovery → the
30 s timeout throws `TimeoutRejectedException``Discover` retry ×2 → `Driver resilience retry`). This is a
genuine production event under real network faults, but it is a **timing race** — connect must succeed, then
the fault must land during the wrapped call, before the session-keepalive drops the driver to `Reconnecting`
(where the wrapped sites no longer fire). It cannot be deterministically forced on the rig with the available
fixtures (opc-plc was down; no on-demand rediscovery trigger).
## Conclusion / recommendation
- **Item 2 (the real code gap — `ResilienceConfig` in the deploy artifact)** is done + live-verified on both
nodes (PR #461).
- **Item 1** is **deterministically proven** by the `DriverResiliencePipelineBuilder` logging unit test (the
`OnRetry`/`OnOpened` handlers emit the exact lines) plus `CapabilityInvoker` retry tests and the factory
override test. The **live** capture is not deterministically achievable from the dev rig — and, more
importantly, the grind proved the issue's proposed write-trigger is **structurally impossible**. The line is
an OpcUaClient-only, transient-fault-mid-`Discover`/`Subscribe` event.
- **Recommend closing item 1** on this finding: the observability surface is unit-proven and the wrapped
dispatch path is now **live-confirmed end-to-end** (authored driver → connected → LDAP write → wrapped
`WriteAsync` → faulted → surfaced). The remaining "eyeball the raw line" is an operator/staging observation
during a real OpcUaClient session fault, not a code deliverable.