diff --git a/CLAUDE.md b/CLAUDE.md index 2858c492..427e71b3 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -929,9 +929,20 @@ to know: store-and-forward sink. A redundant pair therefore sends duplicate live values per historized tag. Deliberately recorded, not "fixed": gating it introduces a failover window with no capture. -Gate status: outbox append, drain, `WriteLiveValues` **accepted by a real historian**, and -**restart-convergence** are all ✅. The final **read-back** hop is ❌ **not** proven — the LAN historian -(`10.100.0.48`) accepts writes but serves no reads under a `License violation: Database tag count exceeds -license tag count`, and the licensed `wonder-sql-vd03` needs the VPN. `EnsureTags` provisioning likewise -could not run there (it is `RemoteGrpc`-only and that CAP is not listening). **Issue #491 stays open for -the read-back hop alone**; treat the rest of continuous value-capture as live-proven. +**Gate COMPLETE — #491 CLOSED 2026-08-04.** Outbox append, drain, `WriteLiveValues`, +**restart-convergence**, `EnsureTags` provisioning (`ensured=2 failed=0`) and **read-back** all ✅. The +read-back leg ran against the licensed `wonder-sql-vd03` with the VPN up: two registers carrying +*distinct non-zero* constants (`8224`, `120`) each read back as its own value — a `0`-valued source +would have proved nothing (the #536 trap). + +⚠️ **A second defect was found and FILED, not fixed (#538): one permanently-failing tag re-writes every +healthy tag on every drain pass, forever.** `DrainOnceAsync` writes **every** per-tag group and then acks +**all-or-nothing**, so one bad tag stops the FIFO head advancing while the good tags' values are +re-submitted to the historian on every retry — duplicate samples, and an outbox that never truncates +(`Capacity` defaults to `0` = unbounded; observed at 8.3 MB). The all-or-nothing ack is deliberate +(`RemoveAsync` truncates *through* an id, so partial acking could drop older unwritten entries) — the +consequence is what is undocumented. + +Also re-confirmed live: **`EnsureTags` provisioning fires only for newly-ADDED historized tags** — +flipping an existing tag's `historianTagname` produces no provisioning at all +(`2026-06-27-historian-gateway-integration-issues.md` Issue 5). diff --git a/docs/Historian.md b/docs/Historian.md index 1ee6935d..89e0edb4 100644 --- a/docs/Historian.md +++ b/docs/Historian.md @@ -114,12 +114,17 @@ source it from there. > hardcodes OPC-DA Good, `192`). Capturing real per-node quality will not persist until the gateway honors > the field — see `GatewayHistorianValueWriter`'s remarks (archreview 06/C-7). -> ✅ **Continuous value capture is LIVE-PROVEN as far as the historian's door -> ([#491](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/491), gate run 2026-08-01 — see -> `docs/plans/2026-08-01-continuous-historization-live-gate.md`).** Against a real -> `ZB.MOM.WW.HistorianGateway` talking to a real AVEVA Historian: deploy → dependency-mux value delta → -> FasterLog outbox append → drain → `WriteLiveValues` **accepted**, and **restart convergence** (the -> recorder re-registers the deployed ref set after a process restart, with no new deployment) both pass. +> ✅ **Continuous value capture is LIVE-PROVEN END-TO-END +> ([#491](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/491) CLOSED — gate run 2026-08-01, +> completed 2026-08-04; see `docs/plans/2026-08-01-continuous-historization-live-gate.md`).** Against a +> real `ZB.MOM.WW.HistorianGateway` talking to the real AVEVA Historian on `wonder-sql-vd03`: deploy → +> `EnsureTags` provisioning → dependency-mux value delta → FasterLog outbox append → drain → +> `WriteLiveValues` → **value read back from the historian**, plus **restart convergence** (the recorder +> re-registers the deployed ref set after a process restart, with no new deployment). +> +> The read-back used two registers carrying **distinct non-zero** constants (`8224`, `120`), each of +> which read back as its own value — a `0`-valued source cannot distinguish a correct value from a +> wrong one. > > ⚠️ The gate found a **production-fatal defect**: the recorder threw `NotSupportedException` on the > **first value it ever appended**, because it touched `Self` after an `await …ConfigureAwait(false)`, @@ -128,12 +133,15 @@ source it from there. > value. Fixed; pinned by a regression test whose outbox fake completes on a **pool** thread (a fake > returning `ValueTask.CompletedTask`, or even `await Task.Yield()`, cannot reproduce it). > -> ❌ **Still unproven: the read-back hop** — no available historian can serve it today (the LAN instance -> accepts writes but serves no reads under a licence tag-count violation; the licensed corporate one needs -> the VPN). `EnsureTags` provisioning is likewise unexercised there (`RemoteGrpc`-only). **#491 stays open -> for that hop alone.** +> ⚠️ **One permanently-failing tag re-writes every healthy tag, forever +> ([#538](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/538)).** `DrainOnceAsync` writes **every** +> per-tag group in a batch and then acks **all-or-nothing**, so a tag whose historian tag does not exist +> stops the FIFO head advancing while the healthy tags' values are re-submitted on every drain pass — +> duplicate samples at identical timestamps, and an outbox that never truncates (`Capacity` defaults to +> `0` = unbounded; observed at 8.3 MB). The all-or-nothing ack itself is deliberate. > -> ⚠️ **Both nodes of a redundant pair historize the same value** — the recorder has no Primary gate, +> ⚠️ **Both nodes of a redundant pair historize the same value +> ([#537](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/537))** — the recorder has no Primary gate, > unlike the alarm store-and-forward sink, so the historian receives duplicate live values per tag. > > **Related, separately open:** `EnsureTags` provisioning fires only for **newly-added** historized 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 fdc7cc91..aa16f14f 100644 --- a/docs/plans/2026-08-01-continuous-historization-live-gate.md +++ b/docs/plans/2026-08-01-continuous-historization-live-gate.md @@ -1,9 +1,15 @@ # Continuous-historization live gate (Gitea #491) -**Date:** 2026-08-01 · **Rig:** `docker-dev` central pair + a real `ZB.MOM.WW.HistorianGateway` -against a real AVEVA Historian · **Outcome:** the gate found and fixed a **production-fatal defect**; -leg 2 CLOSED, leg 1 closed up to the historian's acceptance of the write, with the final read-back -hop blocked by the historian instance (not by OtOpcUa). +**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. + +> **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 +> by the VPN being down. With the VPN up, the run was repeated against the licensed +> `wonder-sql-vd03` and **read-back passed**, as did `EnsureTags` provisioning. See +> §"Read-back leg (2026-08-04)". A second defect — unbounded duplicate re-writes behind one failing +> tag — was found during that run and filed rather than fixed. ## What #491 asked for @@ -122,7 +128,8 @@ curl -s http://10.100.0.48:5220/metrics | grep 'requests_total.*WriteLiveValues' | Recorder spawns + converges on the deployed ref set | ✅ | | Driver value → dependency-mux fan-out → **FasterLog outbox append** | ✅ `hlog.log.0` + `log-commits` grow on both nodes | | Outbox drain → **`WriteLiveValues` accepted by the real historian** | ✅ gateway `outcome="ok"` climbs continuously | -| Value **readable back** from the historian | ❌ blocked — see below | +| Value **readable back** from the historian | ✅ (2026-08-04, `wonder-sql-vd03` — see below) | +| `EnsureTags` provisioning | ✅ (2026-08-04, `ensured=2 failed=0`) | | **Restart convergence** (leg 2) | ✅ | | No `ActorContext` faults on the fixed build | ✅ `0` occurrences | @@ -141,7 +148,66 @@ The boot-time apply re-ran `AddressSpaceApplier`, which re-fed the historized re that had started with an empty set. The retained outbox entries also survived the restart and drained afterwards, exercising the durable crash boundary. -## What is still not proven, and why +## Read-back leg (2026-08-04) — CLOSED + +Re-run with the VPN up, against the **licensed** `wonder-sql-vd03`. The gateway ran locally in Docker +from `~/Desktop/HistorianGateway/docker/` (republish first — a stale `docker/publish` silently ships +old behaviour), reporting every readiness check Healthy including `historian-connection`. The rig's +centrals pointed at `http://host.docker.internal:5221`. + +**`EnsureTags` provisioning also passed here**, which the 2026-08-01 run could not exercise: + +``` +[15:25:59 INF] AddressSpaceApplier: historian provisioning completed (dispatched=2, requested=2, ensured=2, skipped=0, failed=0) +``` + +⚠️ **Provisioning fires only for newly-ADDED historized tags.** Flipping an existing tag's +`historianTagname` produced *no* provisioning line at all — the applier iterates the added set. This is +the already-known limitation in `docs/plans/2026-06-27-historian-gateway-integration-issues.md` Issue 5, +confirmed live. The gate had to add genuinely new tags to exercise the path. + +**Read-back, with values chosen so a wrong answer is visible.** A first attempt read back `0`, which +proves nothing — the same trap #536 recorded ("a sim where every tag reads 0 can't distinguish a +correct decode from a wrong one"). Two registers carrying *distinct non-zero* constants were +historized instead, so a crossed or fabricated value would show: + +| Historian tag | Source | Read back | +|---|---|---| +| `OtOpcUa.Gate491.RegA` | Modbus HR **20** = `8224` | `value=8224 opcQuality=192` ✅ | +| `OtOpcUa.Gate491.RegB` | Modbus HR **3** = `120` | `value=120 opcQuality=192` ✅ | + +Each value matched its own source register — not crossed, not defaulted. Two samples per tag per +instant, one from each pair node (the #537 duplicate-write finding, visible again). + +**Fixture note:** the `otopcua-modbus` fixture was down; the live source used was +`oee-modbus-sim` on **`10.100.0.35:1502`** (another project's stack, but a real Modbus endpoint). Its +registers are static, which is why distinct constants rather than a moving value carry the proof. + +## Second defect found — one failing tag re-writes every healthy tag, forever (filed) + +`DrainOnceAsync` peeks a batch, **writes every per-tag group**, and then acks **all-or-nothing**: + +```csharp +foreach (var group in batch.GroupBy(e => e.Tag, StringComparer.Ordinal)) { + ok = await _writer.WriteLiveValuesAsync(group.Key, values, ct); // every group IS written + if (!ok) allOk = false; +} +if (!allOk) return new DrainResult(false, 0, batch.Count); // ...but nothing is acked +await _outbox.RemoveAsync(batch[^1].Id, ct); +``` + +So a single permanently-failing tag (here: one whose historian tag was never provisioned) means the +FIFO head never advances, and **every healthy tag in that batch is re-written to the historian on every +drain pass** — duplicate samples at the same timestamps, unboundedly, plus an outbox that never +truncates. Observed: the outbox reached **8.3 MB** while the failure persisted, with the gateway's `ok` +and `error` counters both climbing together. + +The all-or-nothing ack is deliberate and the comment explains why (`RemoveAsync` truncates *through* +an id, so partial acking could drop older unwritten entries) — but the consequence is undocumented and +is a real operational hazard, since `Capacity` defaults to `0` (unbounded). Filed, not fixed: the fix +is a per-tag or non-prefix ack, which changes the outbox contract. + +## Environment notes from the 2026-08-01 run (superseded for read-back, still accurate) **The read-back hop.** Neither historian available today can serve it: @@ -181,6 +247,9 @@ because gating it would also mean a failover window with no capture at all. ## Follow-ups -- **#491 stays open** for the read-back hop only, to be closed by re-running the gate against - `wonder-sql-vd03` on the VPN (the `HISTGW_*` live-suite recipe in `CLAUDE.md` still applies). -- File the Primary-gate question for the recorder (secondary finding above). +- **#491 CLOSED** 2026-08-04 — both legs proven. +- **#537** — the recorder has no Primary gate, so both pair nodes write duplicate live values. +- **#538** — one permanently-failing tag re-writes every healthy tag on every drain pass and the + outbox grows unbounded (the all-or-nothing ack above). +- 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.