lmxopcua/docs/plans/2026-08-01-continuous-historization-live-gate.md

# Continuous-historization live gate (Gitea #491)

**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

1. **End-to-end value capture** — deploy → dependency-mux value delta → outbox append →
   `WriteLiveValues` → value readable back from the historian.
2. **Restart convergence** — the recorder re-registers the deployed historized-ref set after a
   process restart (it spawns with an *empty* initial set by design; the set arrives at deploy time).

## The defect the gate found

**`ContinuousHistorizationRecorder` threw on the very first value it ever appended, and historization
then stopped dead.**

`OnValueChangedAsync` awaited `IHistorizationOutbox.AppendAsync(...)` with `ConfigureAwait(false)` and
then touched `Self`. `ConfigureAwait(false)` discards Akka's `ActorTaskScheduler` synchronization
context, so `Self` — which reads `ActorBase.Context` — threw:

```
[ERR] There is no active ActorContext, this is most likely due to use of async operations from within this actor.
System.NotSupportedException: There is no active ActorContext ...
   at ZB.MOM.WW.OtOpcUa.Runtime.Historian.ContinuousHistorizationRecorder.OnValueChangedAsync(...)
      ContinuousHistorizationRecorder.cs:line 294
```

The throw escaped the handler into supervision, which **restarted** the actor — and because
production seeds an **empty** ref set (the deployed set arrives later via `UpdateHistorizedRefs`), the
restart silently discarded every historized ref. Net effect: **one value captured, then nothing, with
no further error to show for it.**

Fix: capture `IActorRef self = Self` *before* the first await and use that — the same idiom the
`GetStatus` handler already applied to `Sender`, whose author clearly knew the hazard for `Sender` and
missed it for `Self`.

### Why 13 unit tests missed it

`InMemoryOutbox.AppendAsync` returned `ValueTask.CompletedTask`. A completed `ValueTask` never yields,
so the `ConfigureAwait(false)` continuation ran **inline on the actor thread with the context still
installed**. The production `FasterLogHistorizationOutbox` fsyncs per entry under `PerEntry` commit
mode, so it genuinely yields — and only then is the context gone.

⚠️ **The obvious regression test was itself vacuous, and only falsification caught that.** The first
version of the fake used `await Task.Yield()`. That does **not** reproduce the bug: `Yield()` posts back
to the *captured* context (Akka's scheduler), so `AppendAsync` completes **on the actor thread**, and the
caller's `ConfigureAwait(false)` then resumes inline right there — context intact. Reverting the
production fix left the new test **green**. The fake has to complete on a **pool** thread with no
synchronization context (`await Task.Delay(1).ConfigureAwait(false)`), which is what a real fsync does.
With that, reverting the fix turns exactly one test red.

Pinned by `ContinuousHistorizationRecorderTests.A_yielding_append_neither_faults_the_actor_nor_loses_the_value`.

## Rig changes

`docker-dev/docker-compose.yml` carried `ServerHistorian__*` but **no `ContinuousHistorization__*` keys
at all**, so the recorder could never spawn on the rig and this gate was unrunnable. Both centrals now
carry them, default-OFF (the recorder needs `ContinuousHistorization:Enabled` **and**
`ServerHistorian:Enabled`, so the default rig stays inert):

| Key | Value |
|---|---|
| `ContinuousHistorization__Enabled` | `${OTOPCUA_CONTHIST_ENABLED:-false}` |
| `ContinuousHistorization__OutboxPath` | `/app/data/historization-outbox` (per-node named volume — survives recreate) |
| `ContinuousHistorization__CommitMode` | `${OTOPCUA_CONTHIST_COMMITMODE:-PerEntry}` |
| `ContinuousHistorization__DrainIntervalSeconds` | `${OTOPCUA_CONTHIST_DRAIN_SECONDS:-2}` |

`ServerHistorian__UseTls` was also parameterized (`${OTOPCUA_HISTORIAN_USETLS:-true}`) — it was
hard-coded `true` on both centrals, which cannot talk to a plaintext h2c gateway.

## Re-running the gate

**Gateway.** The corporate historian (`wonder-sql-vd03`) needs the VPN. A second AVEVA Historian lives
on the **local LAN at `10.100.0.48`** (`DESKTOP-6JL3KKO`, passwordless SSH, PowerShell default shell) and
needs no VPN. Run the gateway *on that box* so it authenticates to the historian and to SQL with the
local Windows identity — no credentials leave the machine, and no Kerberos/GSSAPI container problem:

```bash
# Publish on the Mac (the VM has no credentialed NuGet feed) and copy across:
cd ~/Desktop/HistorianGateway
dotnet publish src/ZB.MOM.WW.HistorianGateway.Server -c Release -o /tmp/histgw-pub -p:UseAppHost=false
tar czf /tmp/histgw-pub.tgz -C /tmp histgw-pub
scp /tmp/histgw-pub.tgz dohertj2@10.100.0.48:C:/Temp/histgw-pub.tgz
ssh dohertj2@10.100.0.48 'cd C:\Temp; tar xzf histgw-pub.tgz; Move-Item histgw-pub histgw'
# …then a run.cmd setting Historian__Host=localhost, RuntimeDb__Enabled/EventReadsEnabled=true with an
# Integrated Security connection string, ApiKeys__Mode=Disabled, Dashboard__DisableLogin=true, and the
# Ldap__* block (AddZbLdapAuth registers a ValidateOnStart that requires a non-empty Ldap:Server even
# when login is disabled), launched detached via Win32_Process.Create.
```

⚠️ **The launcher script must have CRLF line endings.** A batch file written on macOS with LF endings
runs — `@echo off` and the final `dotnet` line execute — but the `set` lines silently do not take
effect, so the gateway boots on `appsettings.json` defaults and fails with a *misleading* error (it
crashed on the LDAP validator while every env var appeared correct in the file). This cost two
debugging cycles.

**Rig:**

```bash
OTOPCUA_HISTORIAN_ENABLED=true OTOPCUA_HISTORIAN_ENDPOINT=http://10.100.0.48:5221 \
OTOPCUA_HISTORIAN_USETLS=false OTOPCUA_CONTHIST_ENABLED=true \
ServerHistorian__ApiKey=histgw_local_vm-gate-placeholder \
docker compose -f docker-dev/docker-compose.yml up -d --force-recreate central-1 central-2
curl -s -X POST http://localhost:9200/api/deployments -H "X-Api-Key: docker-dev-deploy-key" \
     -H "Content-Type: application/json" -d '{"createdBy":"issue-491-gate"}'
```

**The gateway's own `/metrics` is the observation point** — OtOpcUa logs a failed drain only as a
back-off, so the honest counter lives on the gateway side:

```bash
curl -s http://10.100.0.48:5220/metrics | grep 'requests_total.*WriteLiveValues'
```

## Results

| Leg | Result |
|---|---|
| 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 | ✅ (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 |

**Restart convergence evidence.** With `central-2` stopped (so the counter attributes to one node),
`central-1` was restarted with **no new deployment**:

```
before restart: ok=12
[23:51:29 INF] DriverHost central-1:4053: restored served state for applied deployment d8cacd20… on bootstrap
[23:51:29 INF] AddressSpaceApplier: historian provisioning completed (dispatched=1, requested=1, …)
after restart+90s: ok=19
```

The boot-time apply re-ran `AddressSpaceApplier`, which re-fed the historized refs through
`ActorHistorizedTagSubscriptionSink` → `UpdateHistorizedRefs`, and capture resumed against a recorder
that had started with an empty set. The retained outbox entries also survived the restart and drained
afterwards, exercising the durable crash boundary.

## 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:

- **`10.100.0.48`** logs `License violation: Database tag count exceeds license tag count` hourly
  (1780 configured analog tags against a smaller licence). It **accepts** writes — the SQL `INSERT` into
  `Runtime.dbo.History` succeeds and `C:\Historian\original.dat` is appended within seconds — but
  retrieval returns nothing, for *any* tag: even the historian's own `SysTimeSec` yields a single
  boundary row over a 5-minute `wwRetrievalMode='Full'` window. This is an environment/licensing fault,
  entirely outside OtOpcUa.
- **`wonder-sql-vd03`** (the licensed corporate historian, where read/write/alarm-send were previously
  live-validated green) needs the VPN, which is down — its IPs `10.220.157.253` / `.247` are unreachable.

**`EnsureTags` provisioning.** The hook fires and is correctly non-blocking, logging
`dispatched=1, requested=1, ensured=0, skipped=0, failed=1` — but it cannot succeed on this instance:
`EnsureTags` goes through `HistorianClient.OpenSessionAsync`, which is **`RemoteGrpc`-only**, and the
historian's gRPC Client Access Point is not listening on `10.100.0.48`. Port `32565` is held by a
**supervised `autossh` remote-forward from the developer Mac** (`-R 32565:wonder-sql-vd03…:32565`,
deliberate infrastructure — do not kill it; it self-heals anyway), so the CAP process has **no listening
sockets at all**. The gate worked around this by pointing the historized tag at a pre-existing historian
tag via `historianTagname`, which exercises the override resolution path as a bonus.

The consequence is directly visible and is itself a correct-behaviour observation: the tag that exists
writes `ok`, the unprovisioned one returns `Unavailable/SqlException`, its outbox entries are **retained**
rather than dropped, and the drain backs off. No data loss on a failing write.

## Secondary finding — both pair nodes historize the same value

`ContinuousHistorizationRecorder` has **no Primary gate**. With both centrals up, the gateway's `ok`
counter advances twice per value; stopping `central-2` halves it. So a redundant pair sends **duplicate
live values** to the historian for every historized tag.

This contrasts with the alarm store-and-forward sink, which *is* Primary-gated (`drainGate` fed from
`IRedundancyRoleView`) precisely so a pair does not double-deliver. Whether duplicate analog samples are
acceptable (the historian may fold same-timestamp samples) or whether the recorder should take the same
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.

## Follow-ups

- **#491 CLOSED** 2026-08-04 — both legs proven.
- **#537 CLOSED** — the recorder now gates its **capture** (not its drain — the outbox is node-local and
  replicates to nobody, unlike the alarm queue) on `PrimaryGatePolicy.ShouldRecordHistorizedValues`, read
  per value through `IHistorizationRoleView`. It stands down only for a Primary that records the same
  refs — a partner in its own per-cluster mesh — and a node with no cluster-scoped role never stands down.
  See `docs/Historian.md` §"Only the recording Primary captures".
- **#538 CLOSED** — the drain now abandons a tag's queued entries after `MaxWriteAttempts` consecutive
  failures, counted **only across passes where some other tag wrote successfully**, so a whole-backend
  outage still retains everything. The all-or-nothing ack is unchanged. `Capacity` also gained a non-zero
  default (500,000) as the disk backstop for the total-outage case. See `docs/Historian.md` §"A poison tag
  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.