Joseph Doherty
5fdf205caa
Gate: Primary-only typed recording with real status, raw+UNS HistoryRead/Processed parity, HistoryUpdate insert/duplicate/replace/delete + WriteOperate-only and anonymous denied, failover at 1x, Modbus device loss stored as BadCommunicationError then a BadNoCommunication outage marker. Gate found the CLI hid the node-level refusal code (fixed + pinned) and a pre-existing OpcUaClient comms-loss gap (filed separately). docker-dev compose gains ServerHistorian__Backend / __SqlServer__ConnectionString (default Gateway). Claude-Session: https://claude.ai/code/session_01Ef2ozxS7QPanGT8uoATbTe
134 lines
6.8 KiB
Markdown
134 lines
6.8 KiB
Markdown
# Pluggable historian — live gate (T15), 2026-10-09
|
||
|
||
**Verdict: PASSED.** All six legs passed on the docker-dev rig. The rig ran `feat/pluggable-historian` at
|
||
`e2011a65` (plus the gate CLI fix), with the central pair on image `923f5f09e805`, rebuilt for this gate. The SQL Server backend
|
||
pointed at the rig's `sql` container (database `OtOpcUaHistorian`).
|
||
|
||
The gate also found two defects:
|
||
- A display gap in Client.CLI `historyupdate`. It is fixed in the same change.
|
||
- An OpcUaClient driver comms-loss gap that predates this work. It is filed separately.
|
||
|
||
## Setup
|
||
|
||
- `CREATE DATABASE OtOpcUaHistorian` on `otopcua-dev-sql-1`. The schema `hist` was auto-created by the
|
||
bootstrapper on first use: `SchemaVersion`, `Tag`, `Sample`, `Event`.
|
||
- `docker-dev/docker-compose.yml` gained `ServerHistorian__Backend` (`OTOPCUA_HISTORIAN_BACKEND`, default
|
||
`Gateway`) and `ServerHistorian__SqlServer__ConnectionString` (`OTOPCUA_HISTORIAN_SQL`).
|
||
- Central-1 and central-2 were started with:
|
||
|
||
```
|
||
OTOPCUA_HISTORIAN_ENABLED=true OTOPCUA_HISTORIAN_BACKEND=SqlServer OTOPCUA_CONTHIST_ENABLED=true \
|
||
docker compose -f docker-dev/docker-compose.yml up -d central-1 central-2
|
||
```
|
||
|
||
Both containers ran the new image, with `Backend=SqlServer`.
|
||
- Cluster `MAIN` fixtures: opc-plc (`opcplc/plc/FastUInt1`, UInt32, about 1 Hz) and pymodbus `standard`
|
||
(`pymodbus/plc/HR5`).
|
||
- New Calculation String tag `Calc/eng/FastLabel` = `"v" + FastUInt1`. `FastUInt1`, `FastLabel` and later
|
||
`HR5` were marked `isHistorized`. A UNS reference `a/l/e1/FastUInt1` was added. The configuration was
|
||
deployed headlessly (`deploy.sh`), and the tags were provisioned:
|
||
- `hist.Tag` 1 = FastLabel (DataType 9, String)
|
||
- `hist.Tag` 2 = FastUInt1 (5, Int64)
|
||
- `hist.Tag` 3 = HR5 (4)
|
||
- Two data-plane API keys were minted for this gate, each with a `Cluster`-scoped grant:
|
||
- `gate-historyupdate`: ReadOnly | HistoryUpdate (4239)
|
||
- `gate-writeop`: ReadOnly | WriteOperate (159)
|
||
|
||
ACL flag off, which is the rig default.
|
||
|
||
## 1. Recording: Primary-only, typed, real status, one row per value
|
||
|
||
- Rows carry real kinds and statuses:
|
||
- `ValueKind=2` Int64 `477`/`479`/…, status `0`
|
||
- `ValueKind=4` String `v477`/`v479`/…, status `0`
|
||
- startup `ValueKind=0` Empty, with `0x80320000` (BadWaitingForInitialData) and `0x80310000`
|
||
- Primary-only:
|
||
- Central-2 was the driver Primary, and its outbox held `hlog.log.0`.
|
||
- Central-1's outbox directory was empty, and it logged "this node is not the recording Primary … suppressing
|
||
value capture".
|
||
- One row per published value, checked over 82 s:
|
||
- 79 Good FastUInt1 rows and 79 Good FastLabel rows.
|
||
- All 79 pair one-to-one: same `SourceTimeUtc`, `StrValue = 'v' + IntValue`.
|
||
- 0 duplicate values.
|
||
|
||
## 2. HistoryRead through the raw and UNS NodeIds
|
||
|
||
These reads went to central-1 (`:4840`). Central-2's `:4841` returns "Server did not return the
|
||
certificate used to create the secure channel" to the CLI; that rig port-mapping quirk is unrelated.
|
||
|
||
- Raw read 19:00:40–19:00:50 on `ns=2;s=opcplc/plc/FastUInt1` and on `ns=3;s=a/l/e1/FastUInt1`:
|
||
- Identical 8 rows (493…502). Only the header line differs.
|
||
- They equal the `hist.Sample` rows exactly.
|
||
- The gaps (497, 501) come from the driver's 1 s sampling of a 1 s counter. They are in the stored rows and
|
||
in the publish stream alike.
|
||
- Average at 10 s, 19:00:40–19:01:10, through both NodeIds:
|
||
- Both return `497.125 / 507.5 / 517.5`, Good.
|
||
- These equal a direct SQL `AVG` per 10 s bucket (8, 10 and 10 samples).
|
||
|
||
## 3. HistoryUpdate
|
||
|
||
These calls went to central-1 with `-U apikey`. Each was checked by `historyread` and by direct SQL.
|
||
|
||
| Call | Result | Confirmed |
|
||
|---|---|---|
|
||
| insert 18:00:00 = 42 (`gate-historyupdate`) | `GoodEntryInserted` | row `42`, status 0 |
|
||
| repeat insert = 43 | `BadEntryExists`, exit 1 | row still `42` |
|
||
| replace 18:00:00 = 99 | `GoodEntryReplaced` | read and SQL show `99` |
|
||
| replace 18:00:30 (no entry) | `BadNoEntryExists` | — |
|
||
| delete-at-time 18:00:00 | `Good`, exit 0 | read returns 0 values; SQL row gone |
|
||
| insert with `gate-writeop` (WriteOperate only) | Node result `BadUserAccessDenied`, exit 1 | no row |
|
||
| insert, anonymous | Node result `BadUserAccessDenied`, exit 1 | no row |
|
||
|
||
**Gate finding (fixed):** the CLI printed only "(no result returned)" for a refused node. The refusal
|
||
reason is in the node-level result, and the CLI never showed it. `HistoryUpdateCommand` now prints
|
||
`Node result: <code>`, pinned by `Execute_NodeLevelDenial_PrintsNodeResult`. The rows above are from the
|
||
fixed build.
|
||
|
||
## 4. Failover
|
||
|
||
- 19:03:08: `docker stop` central-2, the Primary.
|
||
- 19:02:58: central-1 logged "this node is now the recording Primary … resuming value capture". It was
|
||
promoted when central-2 began leaving. Its outbox appeared, and recording continued with no gap
|
||
(633 → 644 …).
|
||
- Central-2 was restarted and rejoined as standby:
|
||
- Its `hlog.log.0` stayed frozen at 22528 bytes.
|
||
- Central-1's grew (13824 → 15360).
|
||
- Rate over the whole sequence was 1×. Per-30 s counts of FastUInt1 from 19:02:00 on: 30, 29, 29, 30, 30. There
|
||
was no doubling during or after the failover.
|
||
|
||
## 5. Device loss: driver Bad sample and comms-loss outage marker
|
||
|
||
This leg ran on Modbus (`HR5`), as planned. Stopping `otopcua-pymodbus-standard` at 19:09:00 produced:
|
||
|
||
| SourceTimeUtc | ValueKind | Value | Status |
|
||
|---|---|---|---|
|
||
| 19:08:38.2408 | 2 | 5 | `0x00000000` |
|
||
| 19:09:00.2649 | 0 (Empty) | NULL | `0x80050000` BadCommunicationError (driver's own Bad publish) |
|
||
| 19:10:38.2327 | 0 (Empty) | NULL | `0x80310000` BadNoCommunication (#527 watchdog outage marker, ~98 s later) |
|
||
| 19:12:38.4474 | 2 | 5 | `0x00000000` (fixture restarted 19:12:37; recovery re-publish) |
|
||
|
||
This confirms design §9.10 as amended: comms loss is historized as an outage marker. The plan's original
|
||
leg-6 text predated that correction.
|
||
|
||
Reads over the outage:
|
||
- Raw `historyread` shows Bad/Good/Bad/Bad/Good.
|
||
- Average at 120 s gives `5 Uncertain` / `(null) Bad` / `5 Good`.
|
||
|
||
The outage is visible and is not bridged.
|
||
|
||
**Gate finding (pre-existing, filed separately):** stopping opc-plc first produced NO Bad sample. The
|
||
OpcUaClient driver kept serving `FastUInt1 = 745`, status Good, for more than 3.5 minutes. It did not
|
||
recover after opc-plc was restarted either. Its session loss never reaches the node status or driver
|
||
health, so the #527 watchdog cannot fire. This is unrelated to the historian; Modbus behaves as designed.
|
||
|
||
## Restore
|
||
|
||
- The rig was restored afterwards:
|
||
- central-1 and central-2 were recreated with the compose defaults (historian off).
|
||
- The gate tags, script, UNS reference, API keys and ACL rows were removed.
|
||
- The `HR5` and `FastUInt1` TagConfigs were reverted.
|
||
- The configuration was redeployed.
|
||
- `OtOpcUaHistorian` was dropped.
|
||
- The opc-plc and pymodbus fixtures were stopped (normally down).
|
||
- The compose keys stay, defaulting to `Gateway`.
|