docs(#456): live grind finding — retry/breaker write-trigger is structurally impossible #466
@@ -101,6 +101,28 @@ Original recipe (retained): build central-1/central-2 from source → deploy a M
|
||||
grep central-1 logs for `Driver resilience retry` / `circuit-breaker OPENED` / `closed`. NB the Modbus-path caveat
|
||||
above — an idempotent write (or an S7 driver) is the reliable trigger, not a plain subscribe/read.
|
||||
|
||||
## UPDATE (2026-07-15, Gitea #456) — the write-trigger is STRUCTURALLY IMPOSSIBLE; line is OpcUaClient-only
|
||||
|
||||
Ran the full grind (authored a live Modbus equipment tag, connected to the sim, drove LDAP-authed writes, then
|
||||
`docker pause`d the peer). **4 failing wrapped writes → 0 retry/breaker lines** on either central.
|
||||
[Finding artifact](artifacts/456-retry-breaker-live-finding-2026-07-15.md). Root cause corrects the recipe's
|
||||
"idempotent write is the reliable trigger" note:
|
||||
|
||||
- **`ModbusDriver.WriteAsync` swallows every exception → returns `WriteResult(StatusBadInternalError)` — it
|
||||
never throws** (`ModbusDriver.cs:964-967`); the `CapabilityInvoker` only feeds *exceptions* to Polly
|
||||
(`CapabilityInvoker.cs:84/112/147`, no result-status inspection); breaker `ShouldHandle` is `Handle<Exception>`
|
||||
and `Write` retry is pinned to 0 (R2-02/S-8). So a failing wrapped **write** emits **no line by construction**,
|
||||
for **any** polling driver (they all map write faults to a status). Even an idempotent write to a dead endpoint
|
||||
returns a bad status, not a throw.
|
||||
- Polling drivers' other wrapped sites don't throw through the seam either (`SubscribeAsync` lazy poll-reg;
|
||||
`DiscoverAsync` offline/config-driven).
|
||||
- **The line is reachable ONLY for a session driver (OpcUaClient)** whose session faults *mid-`Discover`/
|
||||
`Subscribe`* (the 30 s Polly timeout on the post-connect discovery loop throws `TimeoutRejectedException` →
|
||||
`Discover` retry ×2). That is a genuine production event but an inherent **timing race** (connect must succeed,
|
||||
the fault must land during the wrapped call before keepalive drops the driver to `Reconnecting`) — not
|
||||
deterministically forcible on the rig. The behaviour stays **unit-proven** by the pipeline-builder logging test.
|
||||
**Recommend closing item 1 on this finding.**
|
||||
|
||||
---
|
||||
|
||||
## (Original filed analysis — retained for history; superseded by OUTCOME above)
|
||||
|
||||
@@ -0,0 +1,83 @@
|
||||
# #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.
|
||||
Reference in New Issue
Block a user