Files
lmxopcua/docs/plans/2026-10-09-pluggable-historian-live-gate.md
T
Joseph Doherty 5fdf205caa test(historian): live gate PASSED on docker-dev (SqlServer backend); CLI prints node-level HistoryUpdate result
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
2026-10-09 15:14:46 -04:00

6.8 KiB
Raw Blame History

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.