docs(historian): close #491 — read-back and EnsureTags proven against wonder-sql-vd03
v2-ci / build (push) Successful in 4m11s
v2-ci / unit-tests (push) Failing after 14m17s

The 2026-08-01 run closed every leg except read-back, which no reachable historian could
serve that day (the LAN instance accepts writes but serves no reads under a licence tag-count
violation; the licensed one needed the VPN). With the VPN up the run was repeated against
wonder-sql-vd03 and the remaining legs pass:

- EnsureTags provisioning: ensured=2, failed=0 — the path the LAN box could not exercise at
  all (it is RemoteGrpc-only and that CAP was not listening).
- Read-back: two Modbus registers carrying DISTINCT NON-ZERO constants were historized, and
  each read back as its own value (HR20 -> 8224, HR3 -> 120, quality 192). A first attempt
  read back 0, which proves nothing — the same trap #536 recorded, so the proof was rebuilt
  on values a crossed or fabricated answer could not fake.

Found during the run and FILED rather than 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 a tag whose
  historian tag does not exist stops the FIFO head advancing while the healthy tags' values
  are re-submitted every drain interval; the outbox 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 — so the fix changes the
  outbox contract and does not belong in this commit.

Also re-confirmed live: EnsureTags provisioning fires only for newly-ADDED historized tags, so
flipping an existing tag's historianTagname provisions nothing (Issue 5 of
2026-06-27-historian-gateway-integration-issues.md).

No production code changes — the recorder fix shipped in ad744734.

Claude-Session: https://claude.ai/code/session_015p7wGqy3YpZNCpDzTpGMKo
This commit is contained in:
Joseph Doherty
2026-08-04 11:29:15 -04:00
parent ad74473452
commit e77ea4aa73
3 changed files with 114 additions and 26 deletions
+17 -6
View File
@@ -929,9 +929,20 @@ to know:
store-and-forward sink. A redundant pair therefore sends duplicate live values per historized tag. 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. 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 **Gate COMPLETE — #491 CLOSED 2026-08-04.** Outbox append, drain, `WriteLiveValues`,
**restart-convergence** are all ✅. The final **read-back** hop is ❌ **not** proven — the LAN historian **restart-convergence**, `EnsureTags` provisioning (`ensured=2 failed=0`) and **read-back** all ✅. The
(`10.100.0.48`) accepts writes but serves no reads under a `License violation: Database tag count exceeds read-back leg ran against the licensed `wonder-sql-vd03` with the VPN up: two registers carrying
license tag count`, and the licensed `wonder-sql-vd03` needs the VPN. `EnsureTags` provisioning likewise *distinct non-zero* constants (`8224`, `120`) each read back as its own value — a `0`-valued source
could not run there (it is `RemoteGrpc`-only and that CAP is not listening). **Issue #491 stays open for would have proved nothing (the #536 trap).
the read-back hop alone**; treat the rest of continuous value-capture as live-proven.
⚠️ **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).
+19 -11
View File
@@ -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 > 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). > the field — see `GatewayHistorianValueWriter`'s remarks (archreview 06/C-7).
> ✅ **Continuous value capture is LIVE-PROVEN as far as the historian's door > ✅ **Continuous value capture is LIVE-PROVEN END-TO-END
> ([#491](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/491), gate run 2026-08-01 — see > ([#491](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/491) CLOSED — gate run 2026-08-01,
> `docs/plans/2026-08-01-continuous-historization-live-gate.md`).** Against a real > completed 2026-08-04; see `docs/plans/2026-08-01-continuous-historization-live-gate.md`).** Against a
> `ZB.MOM.WW.HistorianGateway` talking to a real AVEVA Historian: deploy → dependency-mux value delta → > real `ZB.MOM.WW.HistorianGateway` talking to the real AVEVA Historian on `wonder-sql-vd03`: deploy →
> FasterLog outbox append → drain → `WriteLiveValues` **accepted**, and **restart convergence** (the > `EnsureTags` provisioning → dependency-mux value delta → FasterLog outbox append → drain →
> recorder re-registers the deployed ref set after a process restart, with no new deployment) both pass. > `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 > ⚠️ 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)`, > **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 > 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). > 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 > ⚠️ **One permanently-failing tag re-writes every healthy tag, forever
> accepts writes but serves no reads under a licence tag-count violation; the licensed corporate one needs > ([#538](https://gitea.dohertylan.com/dohertj2/lmxopcua/issues/538)).** `DrainOnceAsync` writes **every**
> the VPN). `EnsureTags` provisioning is likewise unexercised there (`RemoteGrpc`-only). **#491 stays open > per-tag group in a batch and then acks **all-or-nothing**, so a tag whose historian tag does not exist
> for that hop alone.** > 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. > 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 > **Related, separately open:** `EnsureTags` provisioning fires only for **newly-added** historized
@@ -1,9 +1,15 @@
# Continuous-historization live gate (Gitea #491) # Continuous-historization live gate (Gitea #491)
**Date:** 2026-08-01 · **Rig:** `docker-dev` central pair + a real `ZB.MOM.WW.HistorianGateway` **Date:** 2026-08-01, completed 2026-08-04 · **Rig:** `docker-dev` central pair + a real
against a real AVEVA Historian · **Outcome:** the gate found and fixed a **production-fatal defect**; `ZB.MOM.WW.HistorianGateway` against a real AVEVA Historian · **Outcome: BOTH LEGS CLOSED.** The gate
leg 2 CLOSED, leg 1 closed up to the historian's acceptance of the write, with the final read-back found and fixed a **production-fatal defect**, and surfaced a second (unfixed, filed) one.
hop blocked by the historian instance (not by OtOpcUa).
> **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 ## 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 | ✅ | | 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 | | 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 | | 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) | ✅ | | **Restart convergence** (leg 2) | ✅ |
| No `ActorContext` faults on the fixed build | ✅ `0` occurrences | | 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 that had started with an empty set. The retained outbox entries also survived the restart and drained
afterwards, exercising the durable crash boundary. 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: **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 ## Follow-ups
- **#491 stays open** for the read-back hop only, to be closed by re-running the gate against - **#491 CLOSED** 2026-08-04 — both legs proven.
`wonder-sql-vd03` on the VPN (the `HISTGW_*` live-suite recipe in `CLAUDE.md` still applies). - **#537** — the recorder has no Primary gate, so both pair nodes write duplicate live values.
- File the Primary-gate question for the recorder (secondary finding above). - **#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.