Joseph Doherty
689fc06e85
Regression check first, since this changes ACK semantics: a normal deploy still records Applied on all six nodes. Then the same induction as #485 — the node now records Failed with a reason while the five nodes that read the real artifact record Applied (pre-fix all six claimed Applied), and the log shows it staying on the PREVIOUS revision rather than the dispatched one, which is what lets a retry land. Values kept flowing throughout (59603, current), and the next real deploy applied normally. Claude-Session: https://claude.ai/code/session_01GASWkNEi68FSCtvr6rLoEW
77 lines
7.2 KiB
Markdown
77 lines
7.2 KiB
Markdown
# Issue #485 — live gate (docker-dev rig)
|
|
|
|
> Verifies the two fixes for #485 — `OpcUaPublishActor` (master `c7f5b9cf`) and `DriverHostActor`
|
|
> (master `5aad1e33`) — on the local `docker-dev` rig: 6 nodes, shared SQL, real Modbus fixture on
|
|
> `10.100.0.35:5020`.
|
|
>
|
|
> **Safety rules followed**: all DB inspection + mutation via `sqlcmd` inside the SQL container; the
|
|
> rig's Modbus fixture is read-only for this gate (no writes to the PLC sim).
|
|
|
|
## Result
|
|
|
|
**Both fixes verified, all three guards observed firing in production, with a live RED control that
|
|
was not staged.** The gate also confirmed a **pre-existing** defect the fixes do not address — the node
|
|
records `Applied` for a deployment it skipped (see "Finding" below).
|
|
|
|
| # | Check | Result | Evidence |
|
|
|---|---|---|---|
|
|
| 1 | RED control — the bug in its natural habitat, unforced | ✅ | site-a-1 hit #485 during the *previous* gate's SQL flapping and had been serving an **empty address space for 34 minutes**: `failed to load artifact … rebuild becomes no-op` followed immediately by `applied plan (kind=PureRemove, added=0, removed=17, rebuild=True)`. Its 17 `ns=2` nodes were gone; a browse returned only the root `OtOpcUa` folder. Nothing was staged to produce this — it was already true on the pre-fix image. |
|
|
| 2 | Rebuilt on the fixed image, the node recovers | ✅ | After `docker compose build` + `--force-recreate`, site-a-1 restored to `raw subtree materialised (containers=16, tags=1)` — 18 `ns=2` nodes. |
|
|
| 3 | Address-space guard fires; nodes survive | ✅ | site-a-1, empty artifact: `OpcUaPublish: no usable artifact for deployment f4b9dd63… — KEEPING the currently served address space rather than tearing it down`. **No `PureRemove`.** Browse before vs after: 18 vs 18, `diff` **identical**. |
|
|
| 4 | Reconcile guard fires; drivers survive | ✅ | `artifact for f4b9dd63… read back empty; skipping reconcile and keeping the 1 running driver(s)`, and the apply still reported `children=1`. Repeated on central-2 with a bigger blast radius: `keeping the 5 running driver(s)`, `children=5`. |
|
|
| 5 | SubscribeBulk guard fires; **live values keep flowing** | ✅ | central-2, `artifact for 8c36a673… read back empty; skipping SubscribeBulk and keeping the live subscriptions`. The decisive proof is the value, not the log: `ns=2;s=pymodbus/plc/HR200X` read **56278 @ 06:59:51** before the induction, then **56336 @ 07:00:21** and **56354 @ 07:00:30** after it (induction at 07:00:07). The subscription was still delivering fresh Modbus data across the event. |
|
|
| 6 | Positive control — a readable artifact still applies | ✅ | Immediately after the guards fired, a genuine deploy applied normally on both nodes: site-a-1 `AddRemoveMix, added=1, removed=1` + `SubscribeBulk pushed 1 references`; central-2 `AddRemoveMix, added=1, removed=1` + `SubscribeBulk pushed 5 references across 4 driver(s)`. The guards suppress the teardown, **not** deployment. |
|
|
| 7 | Control — only the node that saw empty bytes took the guard path | ✅ | Of the six nodes, exactly **one** logged `read back empty` (the paused one); the other five read the real artifact before it was blanked and applied it normally. The induction window is what produced the condition, not a global change. |
|
|
|
|
## How the failure was induced deterministically
|
|
|
|
The original incident was a race (a transient ConfigDb blip landing between the apply and the artifact
|
|
read). Racing it again would be unreliable, so the gate drives the **empty-bytes** branch instead — which
|
|
is byte-for-byte what the code sees when the row cannot be read, and is the branch the driver-side guards
|
|
key on (their *throw* paths already returned early before this work):
|
|
|
|
1. `docker pause` the target node, freezing it mid-cluster.
|
|
2. `POST /api/deployments` — the deployment seals and dispatches while the node cannot process it.
|
|
3. `UPDATE Deployment SET ArtifactBlob = 0x WHERE DeploymentId = <new>`.
|
|
4. `docker unpause` — the node now processes the dispatch and reads an empty artifact.
|
|
|
|
The pause measured **<1s** on both runs, well inside `acceptable-heartbeat-pause = 10s` and SBR's
|
|
`stable-after = 15s`, so the node was never flagged unreachable and no failover was triggered.
|
|
|
|
## Finding — the node records `Applied` for a deployment it skipped (pre-existing, NOT fixed here)
|
|
|
|
Both guards leave the node running its previous configuration, which is the intent. But `ApplyAndAck`
|
|
advances `_currentRevision = revision` and writes `NodeDeploymentState = Applied` **before** it knows
|
|
whether anything was applied — that assignment sits immediately after `ReconcileDrivers`, which returns
|
|
`null` on both the (pre-existing) throw path and the new empty path:
|
|
|
|
```
|
|
[07:00:07 WRN] DriverHost central-2:4053: artifact … read back empty; skipping reconcile …
|
|
[07:00:07 INF] DriverHost central-2:4053: applied deployment 8c36a673… (rev 03b33904…, children=5)
|
|
```
|
|
|
|
`NodeDeploymentState` for that deployment reads `Status = Applied` for central-2. The node now claims a
|
|
revision whose configuration it never applied — and because `HandleDispatchFromSteady` short-circuits on
|
|
a revision match (`dispatch matches current rev; immediate ACK`), **re-dispatching that same revision is
|
|
a no-op**, so the node cannot self-heal. Only a later deployment with a *different* revision recovers it
|
|
(check 6 confirms that path works).
|
|
|
|
This is pre-existing — the throw path has always done it — and is strictly a reporting/convergence bug,
|
|
not a data-plane one: the node keeps serving its last good configuration throughout. The honest fix is to
|
|
ACK `Failed` and leave `_currentRevision` alone when the artifact could not be read, so the normal deploy
|
|
retry heals it. Tracked separately rather than folded in here, because it changes deploy ACK semantics
|
|
fleet-wide.
|
|
|
|
## Addendum — issue #486 fix, live-gated (2026-07-21)
|
|
|
|
The finding above is now fixed (`DriverHostActor.ApplyAndAck` fails the apply when `ReconcileDrivers`
|
|
returns null) and gated on the same rig with the same induction.
|
|
|
|
| # | Check | Result | Evidence |
|
|
|---|---|---|---|
|
|
| 8 | Regression — a normal deploy still ACKs Applied fleet-wide | ✅ | The change alters ACK semantics, so this is the risk that matters. A genuine deploy recorded `Status = Applied` on **all six** nodes. |
|
|
| 9 | An unreadable artifact now ACKs Failed, with a reason | ✅ | central-2 recorded `Status = Failed` + `the deployment artifact could not be read (ConfigDb unreachable, or the row is missing/empty); nothing was applied`. The five nodes that read the real artifact recorded Applied — so the fleet view now distinguishes them. Pre-fix, all six claimed Applied. |
|
|
| 10 | The revision is NOT advanced | ✅ | `apply of a855dd9e… FAILED — … Staying on revision 5bc0d9f3…` — the **previous** revision, not the dispatched `583122b7…`. This is what stops `HandleDispatchFromSteady` from short-circuiting a retry of that revision. |
|
|
| 11 | The node keeps serving throughout (#485 still holds) | ✅ | The #485 guard fired first (`keeping the 5 running driver(s)`), and `ns=2;s=pymodbus/plc/HR200X` read **59603 @ 07:27:28**, live and current, after the Failed apply. Failing the apply reports the truth; it does not tear anything down. |
|
|
| 12 | The node recovers on the next real deploy | ✅ | The following deployment applied on central-2 (`children=5`) and recorded Applied on all six nodes. |
|