From 5da7ba65170eafd740ee93ac26ad8dfe3740d776 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 15 Jul 2026 14:48:03 -0400 Subject: [PATCH] =?UTF-8?q?docs(#456):=20live=20grind=20finding=20?= =?UTF-8?q?=E2=80=94=20write-trigger=20structurally=20impossible?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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; 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. --- .../FOLLOWUP-10-resilience-dispatch-gap.md | 22 +++++ ...6-retry-breaker-live-finding-2026-07-15.md | 83 +++++++++++++++++++ 2 files changed, 105 insertions(+) create mode 100644 archreview/plans/artifacts/456-retry-breaker-live-finding-2026-07-15.md diff --git a/archreview/plans/FOLLOWUP-10-resilience-dispatch-gap.md b/archreview/plans/FOLLOWUP-10-resilience-dispatch-gap.md index 998438c9..078872c8 100644 --- a/archreview/plans/FOLLOWUP-10-resilience-dispatch-gap.md +++ b/archreview/plans/FOLLOWUP-10-resilience-dispatch-gap.md @@ -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` + 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) diff --git a/archreview/plans/artifacts/456-retry-breaker-live-finding-2026-07-15.md b/archreview/plans/artifacts/456-retry-breaker-live-finding-2026-07-15.md new file mode 100644 index 00000000..93f341d8 --- /dev/null +++ b/archreview/plans/artifacts/456-retry-breaker-live-finding-2026-07-15.md @@ -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` (`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.