diff --git a/CLAUDE.md b/CLAUDE.md index 60d871cf..ad5c1400 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -936,8 +936,8 @@ read-back leg ran against the licensed `wonder-sql-vd03` with the VPN up: two re *distinct non-zero* constants (`8224`, `120`) each read back as its own value — a `0`-valued source would have proved nothing (the #536 trap). -**Both gate findings are now CLOSED — #537 (Primary gate) and #538 (poison tag). Two things to know -before touching either.** +**Both gate findings are now CLOSED and separately live-gated — #537 (Primary gate) and #538 (poison +tag); evidence in the same plan doc. Two things to know before touching either.** - **#538 — the discriminator is "did another tag write this pass?", NOT a failure count.** `DrainOnceAsync` writes every per-tag group and acks **all-or-nothing** (deliberate: `RemoveAsync` truncates *through* an diff --git a/docs/plans/2026-08-01-continuous-historization-live-gate.md b/docs/plans/2026-08-01-continuous-historization-live-gate.md index ebeabbb2..0cc95546 100644 --- a/docs/plans/2026-08-01-continuous-historization-live-gate.md +++ b/docs/plans/2026-08-01-continuous-historization-live-gate.md @@ -2,7 +2,8 @@ **Date:** 2026-08-01, completed 2026-08-04 · **Rig:** `docker-dev` central pair + a real `ZB.MOM.WW.HistorianGateway` against a real AVEVA Historian · **Outcome: BOTH LEGS CLOSED.** The gate -found and fixed a **production-fatal defect**, and surfaced a second (unfixed, filed) one. +found and fixed a **production-fatal defect**, and surfaced two more (#537, #538) — both since fixed and +live-gated in turn; see §"Live gate for the two fixes" at the end of this document. > **2026-08-04 update — the gate is complete.** The 2026-08-01 run closed everything except the > read-back hop, which was blocked by the only historian reachable that day (a licence violation) and @@ -245,6 +246,12 @@ acceptable (the historian may fold same-timestamp samples) or whether the record gate is a **design decision that has not been made** — recorded here rather than silently "fixed", because gating it would also mean a failover window with no capture at all. +> **Resolved (2026-08-04, #537).** The decision went to gating the **capture**, not the drain — the +> reverse of what this paragraph anticipated, because the historization outbox is node-local and +> replicates to nobody, so a drain-only gate leaves the standby's queue growing forever with no one to +> empty it. The failover window is real and accepted; it is bounded by the promoted node's first +> redundancy snapshot, and the live gate below exercises it. See §"Live gate for the two fixes". + ## Follow-ups - **#491 CLOSED** 2026-08-04 — both legs proven. @@ -260,3 +267,74 @@ because gating it would also mean a failover window with no capture at all. no longer pins the outbox". - Still open from before this gate: `EnsureTags` fires only for newly-*added* historized tags (`2026-06-27-historian-gateway-integration-issues.md` Issue 5) — re-confirmed live here. + +--- + +# Live gate for the two fixes (#537, #538) — 2026-08-04, PASSED + +Run against the same rig as the read-back leg, with `otopcua-host:dev` rebuilt at `e7fbe977`. + +**Rig.** docker-dev central pair (both `admin,driver,cluster-MAIN`), `ContinuousHistorization__Enabled=true` +on both; local `zb-historiangw` container against the real AVEVA Historian on `wonder-sql-vd03` (VPN up). + +**Source.** The project's own Modbus fixture, brought back up +(`ssh dohertj2@10.100.0.35 'cd /opt/otopcua-modbus && docker compose --profile standard up -d'`) and driven +by hand-written **Modbus FC6 writes** so the value stream is under the gate's control rather than the +fixture's. Both the project fixture and `oee-modbus-sim` hold *static* registers, and a static source +produces no mux fan-out at all — the recorder captures once at deploy and then nothing, which reads exactly +like a broken recorder. Driving the registers is what makes the rate measurements below mean anything. +`MAIN-modbus-dev` was repointed back to `10.100.0.35:5020`, undoing the temporary `:1502` repoint the +read-back leg made while the fixture was down. + +**The poison tag is the real shape, not a synthetic fault.** `GATE491-B`'s `historianTagname` was *changed* +on an *existing* tag to `OtOpcUa.Gate538.PoisonTag`. Issue 5 guarantees a changed name is never provisioned, +so its writes fail permanently against a historian that has no such tag — which is how #538 was reached in +the first place. `GATE491-A` kept `OtOpcUa.Gate491.RegA` (already provisioned) as the healthy tag. + +## #537 — only the recording Primary captures + +| Leg | Observation | +|---|---| +| Both nodes up | central-1 (Secondary) logged, **once**, `ContinuousHistorization: this node is not the recording Primary for its address space; suppressing value capture…`. Its outbox file froze at its 16:15 size while central-2's kept growing. | +| Steady state | 6 value changes × 2 historized tags → gateway `WriteLiveValues{ok}` **+12 exactly**. Pre-fix this was +24 (measured on the #491 gate as "twice per value, halving when one central stopped"). | +| Failover | central-2 stopped → central-1 logged `…this node is now the recording Primary…; resuming value capture` and captured every subsequent change. | +| Return | central-2 restarted → demoted, logged the suppression line; 5 changes → `ok` **+10**, still one node. | + +The failover leg is the one worth keeping: gating the *capture* is only defensible if promotion resumes it +promptly, and the gate is read per value rather than latched precisely so it does. + +## #538 — a poison tag no longer pins the head + +| Leg | Observation | +|---|---| +| Quarantine fires | `ContinuousHistorization: historian tag OtOpcUa.Gate538.PoisonTag has failed 6 consecutive write attempts while other tags wrote successfully; discarding 1 queued sample(s) so the outbox can drain.` | +| Head advances | 5 value changes over 30s → `ok` **+5** and `error` **+5**: exactly one write per tag per change, against a **2 s** drain interval. Pre-fix the healthy tag's entries were re-submitted on every pass. | +| **Idle is silent** | 40 s with **no** value changes → `ok` and `error` both unchanged, outbox byte size flat. | +| Backlog | On promotion, central-1 cleared a 10-sample poison backlog in a single pass (`discarding 10 queued sample(s)`). | + +⚠️ **The idle leg is the decisive one, and it is the only one that could not be faked.** The driven-rate +legs show a *rate* that happens to look right; a pre-fix build with a pinned head re-writes its queued +healthy entries on every drain pass **whether or not anything new arrives**, so its counters climb during a +quiet window with no input at all. Flat counters over 40 idle seconds is the observation the bug cannot +produce. + +## Incidental finding — a node restart cures an unprovisioned tag + +central-2's restart logged `AddressSpaceApplier: historian provisioning completed (dispatched=2, +requested=2, ensured=2, skipped=0, failed=0)` and the poison tag **started succeeding** — `error` stopped +moving from that point. A full address-space rebuild at boot treats every historized tag as *added*, so it +re-runs `EnsureTags` over the whole set, where the incremental deploy that introduced the renamed tag did +not (`changed=3`, no provisioning line). + +So **restarting the node is a usable workaround for Issue 5**: a changed `historianTagname` is never +provisioned by the deploy that changes it, but is by the next boot. Recorded against Issue 5 rather than +treated as a fix — it is a side effect of the rebuild path, not a deliberate behaviour, and it means an +operator who restarts a node while diagnosing "my tag isn't historizing" makes the symptom disappear +without learning the cause. + +## Rig state left behind + +The gate config is still in place: `GATE491-A`/`GATE491-B` on HR5/HR6 of the project fixture, the latter +still named `OtOpcUa.Gate538.PoisonTag` (now provisioned, so no longer poison), `MAIN-modbus-hr200` / +`MAIN-modbus-gate491` de-historized onto HR7, and both centrals running with historization enabled against +the local gateway container.