dohertj2/lmxopcua
1
0
Fork 0
Code Issues 14 Pull Requests Actions Packages Projects Releases Wiki Activity

docs(plans): R3-02 T19 live gate — PASS on docker-dev at 97cb5cefb6d2: a constant Modbus register (HR5=5) re-publishes 5 Good on raw AND its UNS mirror after a 2-min fixture outage with no value change (0x80050000 → BadNoCommunication → Good), calc follows input quality with an unchanged value, comms_latched_refs 0, deadband-1000 and operator-Restart legs pass; first cycle was vacuous (fixture re-seeds registers on restart) and re-run; wire never carries a value with a Bad status (SDK NodeState.ReadAttribute); MQTT leg not run

Browse Source
This commit is contained in:
Joseph Doherty
2026-08-20 14:33:38 -04:00
parent 1234d869c0
commit 12faa423d0
2 changed files with 121 additions and 8 deletions
Download Patch File Download Diff File Expand all files Collapse all files
archreview/plans/R3-02-stale-good-family-plan.md
+116 -4
View File
@@ -873,10 +873,11 @@ this plan each appended last:
## Outstanding
- **T19 — the live gate (merge-blocking).** Not run: it needs the docker-dev rig plus the shared Modbus
fixture, and it is the only evidence that the identical-value recovery works end to end on a real
device. Recipe unchanged in §Live gate; the constant HR[5] vs auto-incrementing HR[100] pairing is what
makes it non-vacuous.
- **T19 — the live gate: RUN 2026-08-20, PASS** on the Modbus / calc / deadband / operator-restart legs
(see "Live gate result" below). The MQTT leg (step 12) was **not run** — it needs the
`docker-compose.mqtt.yml` overlay plus the authenticated Mosquitto fixture and was outside the gate
session's brief; T2–T5 stay covered by their driver-level tests. The VT leg was folded into the
Calculation leg (same seams, same contract; no VirtualTag was authored).
---
@@ -908,3 +909,114 @@ says, i.e. the same class of bug this plan exists to close, one hop further out.
**STATUS.md corrected:** the anonymous Runtime.Tests flake is
`DriverHostActorNativeAlarmAckRoutingTests.RouteNativeAlarmAck_routes_to_driver_AcknowledgeAsync_with_principal`
— untouched by this branch, known #500 profile, 3× green in isolation per the reviewer.
## Live gate result (2026-08-20, T19) — **PASS** on docker-dev (Modbus const register + UNS mirror + Calculation; deadband + operator-restart legs)
Rig: `docker-dev/docker-compose.yml` on OrbStack, image `otopcua-host:dev` = `97cb5cefb6d2` (master `b9b3cf9a`) on all six
containers (parity via `docker inspect --format '{{.Image}}'`), `DisableLogin=true`, ACL off (the S18 re-gate that ran first on
the same image had its override removed and its rows deleted before this gate). Deploys via `./docker-dev/deploy.sh`. Modbus
fixture `otopcua-pymodbus-standard` on `10.100.0.35:5020`, stopped/started over SSH. Client.CLI `subscribe -i 500`, one process
per node, anonymous, against central-1 (`opc.tcp://localhost:4840`).
**Authoring (by SQL, then deployed `79262f19…`):** raw tags `MAIN-modbus-hr5` (`HR5`, holding register 5, UInt16) and
`MAIN-modbus-hr100` (`HR100`, the auto-increment register — re-added; the seed had only `HR200`); UNS `a` / `l` / equipment `e1`
(`EQ-32296cc68964` — the deploy gate enforces `[a-z0-9-]{1,32}` segment names and the `EQ-<12 hex of uuid>` id derivation, so the
plan's `A`/`L`/`E1` literals are unauthorable) with `UnsTagReference` → `HR5`; driver `Calc` (`Calculation`) / device `eng` / tag
`HR5x2` bound to script `return Convert.ToInt32(ctx.GetTag("pymodbus/plc/HR5").Value) * 2;`. Nodes: `ns=2;s=pymodbus/plc/HR5`,
`ns=3;s=a/l/e1/HR5`, `ns=2;s=Calc/eng/HR5x2`, `ns=2;s=pymodbus/plc/HR100`.
**Recipe correction — the first cycle was vacuous, and the fixture itself said so.** `HR5` read **`1005`** before the first
outage (someone had written register 5 since the fixture was last restarted — `[0,31]` is a writable block), and
`docker stop`/`start` re-seeds the simulator from `standard.json`, so the value came back as **`5`**. A Good re-publish after a
value change proves nothing (the exact trap the plan's HR[5]/HR[100] pairing exists to avoid). The cycle was re-run with `5`
on both sides; that second cycle is the evidence below. **Check the register reads its seed value before stopping the
fixture** — a restart silently resets every written register.
### Cycle 2 — identical-value recovery (non-vacuous): PASS
| node | before | Modbus per-tag degrade | watchdog re-stamp | recovery |
|---|---|---|---|---|
| `ns=2;s=pymodbus/plc/HR5` (raw) | `5 Good` (one notification, 18:17:48.635 — static, confirmed by silence) | `(0x80050000)` @ 18:20:49.268 | `(0x80310000)` @ 18:21:08.596 | **`5 Good` @ 18:21:48.617** |
| `ns=3;s=a/l/e1/HR5` (UNS mirror) | `5 Good` same timestamp | `0x80050000` @ 18:20:49.268 (same ms) | `0x80310000` @ 18:21:08.596 | **`5 Good` @ 18:21:48.617** (same ms as raw) |
| `ns=2;s=Calc/eng/HR5x2` | `10 Good` | `0x80050000` @ 18:20:49.268 | `0x80310000` @ 18:21:08.596 | **`10 Good` @ 18:21:48.617** |
| `ns=2;s=pymodbus/plc/HR100` (positive control) | counting 1/s | `0x80050000` @ 18:20:49.268 | `0x80310000` @ 18:21:08.596 | `1 Good` @ 18:21:48.617, then counting |
Fixture stopped 18:19:27, started 18:21:35. The plant value of HR5 was `5` before, during (re-seeded) and after — the
`5 Good` at 18:21:48 can only be the force re-publish. Raw and UNS fan in the same millisecond at every transition (one publish,
one fan-out). central-1:
```
[18:21:08 WRN] DriverInstance MAIN-modbus: no successful read for 00:01:43… while reporting Degraded (Transport not connected) — declaring comms lost and reconnecting
[18:21:08 WRN] DriverInstance MAIN-modbus: disconnect observed (no successful read for 104s while reporting Degraded); reconnecting
[18:21:08 INF] DriverHost central-1:4053: driver MAIN-modbus disconnected — 4 value node(s) marked BadNoCommunication (value retained)
[18:21:28 WRN] Driver resilience circuit-breaker OPENED: instance=MAIN-modbus … capability=Initialize breakDuration=00:00:15: Connection refused
[18:21:48 INF] Driver resilience circuit-breaker closed (recovered) … / DriverInstance MAIN-modbus: reconnected / subscribed to 3 refs (poll-sub-3)
```
(the first cycle — 18:15:26 → 18:17:48 — produced the identical sequence with `1005 → 5`, and is recorded only as the vacuous
control). Four nodes = HR5, HR100, HR200 and the UNS mirror — the calc node is not the Modbus driver's and follows through its
input instead, which is the STAB-19 leg: `HR5x2` carried the input's sub-code at both transitions (`0x80050000` then
`0x80310000`) and came back `10 Good` with the input.
**`comms_latched_refs`: 0.** `otopcua_driver_comms_latched_refs` is absent from `/metrics` after every cycle (a counter that has
never been added is not exported; `apikey_store_bounded` on the same endpoint proves the exporter works), and
`grep -ci "still BadNoCommunication\|latched"` on central-1 over the whole session = **0**.
### Timing notes (observations, not failures)
- **Modbus's own per-tag degrade took ~82 s, not the plan's "1–2 s".** Fixture stopped ≈18:19:27 (the `docker stop` itself
took 11 s of SIGTERM grace), first `0x80050000` at 18:20:49. The stopped container's published port is simply gone, so the
driver's existing TCP socket sees no RST — each poll rides out `TimeoutMs=2000` plus the probe cadence before the transport is
declared not connected. Pre-existing Modbus behaviour, outside this plan's seams; the watchdog's 90 s `LastSuccessfulRead`
freeze then lands ≈20 s after that. Worth knowing when reading a timeline: "Bad within ~90 s" held (82 s), the
`BadNoCommunication` re-stamp landed at 101–104 s.
- Recovery was 11–13 s after `docker start` (breaker `Initialize` half-open 15 s after a refused connect that pre-dated the
fixture coming up), inside the plan's ~15 s.
### "Last value retained" is server-side state and NOT observable over the wire — worth knowing before the next gate
Every Bad notification above prints an **empty** value, calc included, although `CalculationDriver.MarkInputsBad` carries
`st.LastValue` and the node-manager test `OtOpcUaNodeManagerWriteStatusesTests` asserts the SDK variable keeps it. The reason
is the OPC Foundation stack, not this code: `NodeState.ReadAttribute` (UA-.NETStandard `1.5.377.21`,
`Stack/Opc.Ua.Core/Stack/State/NodeState.cs:3376-3378`) does
`if (StatusCode.IsBad(value.StatusCode)) value.WrappedValue = Variant.Null;` on every read and every monitored-item sample. So
a client can never see a value alongside a Bad status from this server; the retention is what lets the *next Good* re-publish
carry the same value and what the `(value, status)`-keyed dedup compares against. The plan's step-7 assertion "the last value
is retained on the calc/VT nodes" is therefore checked by the unit tests, not by a subscription; the wire-visible contract is
the status sub-code and the identical-value Good after recovery, both of which passed. A CLI `read` of a Bad node throws
client-side (`NodeCache.FetchValueAsync`), so that path cannot show it either.
### Step 10 — deadband falsification leg: PASS (recovered; audit Warning correctly absent)
`HR5` TagConfig given `"deadband": 1000`, deployed `b9863c2b…` at 18:25:32 (a driver-restarting apply: the T11 PostStop mark
`4 value node(s) marked BadNoCommunication (value retained)` and `subscribed to 3 refs (poll-sub-2)` landed in the same second;
no Bad reached the 500 ms subscriptions). Fixture stopped 18:26:21, started 18:28:28. `HR5` raw + UNS: `5 Good` →
`0x80050000` @ 18:27:42.989 → `0x80310000` @ 18:28:02.501 → **`5 Good` @ 18:28:42.518**; `HR5x2` `10 → Bad → Bad → 10 Good`
at the same instants. The driver-side deadband cache did not survive the reconnect (`TeardownAsync` clears it), so the Good
re-publish arrived with no audit Warning and the counter stayed absent — the "recovers" outcome, which is the passing one.
Deadband removed and redeployed (`e0a466c1…`) at restore.
### Step 11 — operator Restart leg: PASS
`/hosts → pymodbus (MAIN-modbus) → Controls → Restart → Confirm restart` at 18:30:42. central-1:
`restarting driver MAIN-modbus by request of multi-role-test` → `driver MAIN-modbus disconnected — 4 value node(s) marked
BadNoCommunication (value retained)` → `DriverInstance MAIN-modbus: connected` → `subscribed to 3 refs (poll-sub-1)`, all in
18:30:42. Subscriptions: `HR5` raw `5 Good @ 18:30:42.375` and `HR5x2` `10 Good @ 18:30:42.375` — **a fresh Good notification
with an unchanged value** on a static register, i.e. the re-subscribe initial push plus the status-keyed calc re-publish;
`HR100` resumed counting (`283, 285, 287 …`). As in R3-03's gate, **no Bad flash was visible at 500 ms sampling** — the mark and
the reconnect fall inside one second and the SDK's queue coalesces them; the server-side mark is in the log.
### Not run
- **Step 12 (MQTT retained replay + rebuild-shows-cached-value):** needs the `docker-compose.mqtt.yml` overlay and the
authenticated Mosquitto fixture; outside this session's brief. T2–T5 remain covered by `Driver.Mqtt.Tests` (initial push,
`ConnectionLost` stale, Sparkplug variants) and the driver-level recovery test from T5.
- **VirtualTag (`VT5`):** not authored; the Calculation tag exercises the same `InputQuality.WorstOf` / hold-on-Bad /
status-keyed-dedup contract through `DependencyConsumerMuxAdapter`, and `VirtualTagActor` has the T16 unit pair.
### Restore
Deadband removed, final deploy `e0a466c1…` Sealed; `HR5` reads `5 Good`. The gate's rows (`HR5`, `HR100`, UNS `a/l/e1` +
mirror, `Calc`/`eng`/`HR5x2` + script) are **kept** — like R3-03's `HR100`, they are the only static-vs-changing pair and the only
calc on the rig, and the next quality gate will want them. Modbus fixture running (`Up` on `10.100.0.35`); rig UP on
`97cb5cefb6d2` ×6 with no overrides.
archreview/plans/R3-02-stale-good-family-plan.md.tasks.json
+5 -4
View File
@@ -10,7 +10,7 @@
},
{
"id": "T2",
"subject": "MQTT plain-mode initial push of cached snapshots on SubscribeAsync — push-model forceRaise (05/STAB-18 shape b)",
"subject": "MQTT plain-mode initial push of cached snapshots on SubscribeAsync \u2014 push-model forceRaise (05/STAB-18 shape b)",
"status": "done",
"blockedBy": []
},
@@ -54,7 +54,7 @@
},
{
"id": "T8",
"subject": "DriverHostActor.FanCommsLossToValueNodes: one BadNoCommunication status batch over raw + UNS nodes on ConnectivityChanged(false); nothing on reconnect (new method — R3-03 boundary)",
"subject": "DriverHostActor.FanCommsLossToValueNodes: one BadNoCommunication status batch over raw + UNS nodes on ConnectivityChanged(false); nothing on reconnect (new method \u2014 R3-03 boundary)",
"status": "done",
"blockedBy": [
"T7"
@@ -144,10 +144,11 @@
{
"id": "T19",
"subject": "LIVE GATE: docker-dev comms-loss -> identical-value recovery (Modbus constant HR[5] raw+UNS, calc, VT, deadband falsification leg, restart leg, MQTT retained replay)",
"status": "pending",
"status": "done",
"blockedBy": [
"T18"
]
],
"note": "RUN 2026-08-20 on docker-dev at 97cb5cefb6d2 (master b9b3cf9a): PASS. Non-vacuous leg \u2014 HR5 = 5 before and after a 2-min fixture stop, re-published 5 Good on raw AND UNS (same ms) with no value change; calc HR5x2 10\u21920x80050000\u21920x80310000\u219210 Good; HR100 positive control; comms_latched_refs 0, no audit Warning; deadband-1000 leg recovered; operator Restart leg re-published unchanged values with no visible Bad flash at 500 ms. First cycle was vacuous (1005\u21925: the fixture re-seeds registers on restart) and was re-run. 'Value retained' is unobservable over the wire \u2014 the SDK's NodeState.ReadAttribute nulls the value on any Bad status. NOT run: step 12 MQTT leg (needs the mqtt overlay + fixture); VT folded into the calc leg."
}
]
}