Files
lmxopcua/docs/plans/2026-10-10-questdb-historian-live-gate.md
T

12 KiB
Raw Blame History

QuestDB historian — live gate (T9), 2026-10-11

Verdict: PASSED. All six legs of spec §7 passed on the docker-dev rig. The rig ran feat/questdb-historian at 2ebe0a42, with the central pair on image 0701f6a833ea, rebuilt for this gate. The QuestDB backend pointed at the overlay questdb service (questdb/questdb:10.0.1, docker-dev/docker-compose.questdb.yml), with default table prefix hist_.

The gate also produced two findings, neither in the QuestDB backend. Both are described under "Gate findings" below:

  • A crash failover (SIGKILL of the recording Primary) leaves a recording gap of about 30 s. This is the #537 Primary-gated capture waiting for Akka downing; it is backend-independent.
  • One libgssapi_krb5.so.2 load error is printed per central boot. It is benign.

Setup

  • docker-dev/docker-compose.yml gained ServerHistorian__QuestDb__RetentionDays (OTOPCUA_HISTORIAN_QUESTDB_RETENTION_DAYS, default empty = no TTL) on both centrals, beside the existing ServerHistorian__QuestDb__ConnectionString (OTOPCUA_HISTORIAN_QUESTDB).

  • Central-1 and central-2 were started with:

    OTOPCUA_HISTORIAN_ENABLED=true OTOPCUA_HISTORIAN_BACKEND=QuestDb OTOPCUA_CONTHIST_ENABLED=true \
    docker compose -f docker-dev/docker-compose.yml -f docker-dev/docker-compose.questdb.yml up -d --no-deps central-1 central-2
    

    With RetentionDays empty, both nodes booted cleanly; the empty value binds as "no TTL". Each logged QuestDB historian connection pool: Maximum Pool Size = 24 (default cap). (the final-review I-1 fix).

  • Cluster MAIN fixtures on 10.100.0.35: opc-plc (opcplc/plc/FastUInt1, UInt32, about 1 Hz) and pymodbus standard (pymodbus/plc/HR5).

  • Gate configuration, written to the config DB and deployed headlessly (deploy.sh, deployment 0b4f5208):

    • New Calculation String tag Calc/eng/FastLabel = "v" + FastUInt1 (script MAIN-script-fastlabel).
    • FastUInt1, FastLabel and HR5 were marked isHistorized.
    • A UNS reference a/l/e1/FastUInt1 was added.
  • Tags were provisioned at deploy (dispatched=3, requested=3, ensured=3, skipped=0, failed=0 on both nodes). hist_tag:

    name data_type
    Calc/eng/FastLabel 9 (String)
    opcplc/plc/FastUInt1 5 (Int64)
    pymodbus/plc/HR5 4
  • Tables at first boot, from tables():

    • hist_sample, hist_event: WAL, PARTITION BY DAY, ttlValue 0.
    • hist_tag: WAL, PARTITION BY YEAR.
  • Two data-plane API keys were minted for the gate, each with a Cluster-scoped grant. The ACL flag stayed off, which is the rig default.

    • gate-historyupdate: ReadOnly | HistoryUpdate (4239)
    • gate-writeop: ReadOnly | WriteOperate (159)

Direct queries used QuestDB REST: curl -G localhost:19000/exec --data-urlencode "query=…".

1. Recording: Primary-only, typed, real status, one row per value

  • Rows carry real kinds and statuses:
    • kind=2 Int64 int_value 278 (with num_value 278.0), status 0.
    • kind=4 String v278, status 0.
    • At startup, kind=0 Empty with 2150760448 (0x80320000 BadWaitingForInitialData) and 2150694912 (0x80310000 BadNoCommunication). These match the SQL Server gate.
  • Primary-only:
    • Central-2 was the recording Primary, and its outbox hlog.log.0 grew.
    • Central-1 logged "this node is not the recording Primary … suppressing value capture". Its hlog.log.0 kept its 2026-10-09 19:13 mtime and was not written.
  • One row per value, from 07:43:20 onwards:
    • 57 FastUInt1 rows over 57 distinct timestamps; 57 FastLabel rows over 57.
    • All 57 pair one-to-one: same ts, and str_value = 'v' + int_value.
  • Outbox carry-over across a backend switch. Two rows carry source time 2026-10-09T19:13:40.129127Z (296 / v296) with server_ts 07:42:27, before the deploy. They were un-drained entries left in central-2's outbox by the 2026-10-09 SQL Server gate, and they drained into QuestDB at boot. An outbox entry outlives the backend it was captured under, by design: the outbox is backend-neutral.

2. HistoryRead through the raw and UNS NodeIds

All reads went to central-1 (:4840).

  • Raw read, 07:44:00–07:44:10, on ns=2;s=opcplc/plc/FastUInt1 and on ns=3;s=a/l/e1/FastUInt1:
    • Both return the identical 10 rows, 271…280, all Good.
    • They equal the direct query select ts, int_value, status from hist_sample where tag=… and not deleted exactly, at microsecond precision (for example 07:44:00.952990Z).
  • Average at 10 s, 07:44:00–07:44:30, through both NodeIds:
    • Both return 275.5 / 285.5 / 295.5, all Good.
    • The direct avg(int_value) per 10 s bucket gives 275.5 / 285.5 / 295.5, over 10, 10 and 10 samples.

3. HistoryUpdate

These calls went to central-1 on ns=2;s=opcplc/plc/FastUInt1, with -U apikey. Each was checked by historyread and by a direct query.

Call Result Confirmed
insert 06:00:00 = 42 (gate-historyupdate) GoodEntryInserted row 42, status 0, deleted=false
repeat insert = 43 BadEntryExists row still 42
replace 06:00:00 = 99 GoodEntryReplaced row 99
replace 06:00:30 (no entry) BadNoEntryExists —
update 06:01:00 = 11 (absent) GoodEntryInserted row 11
delete-at-time 06:00:00 Good tombstone row: int_value NULL, status 0x809B0000, deleted=true
insert over the tombstone, 06:00:00 = 55 GoodEntryInserted (ledger ruling: an insert over a tombstone is an insert) read returns 55
delete-at-time 06:00:00 again Good read returns only 06:01:00 = 11
insert with gate-writeop (WriteOperate only) Node result BadUserAccessDenied no row
insert, anonymous Node result BadUserAccessDenied no row
insert at 1969-12-31 (RC1) BadOutOfRange no row

No QuestDB UPDATE or DELETE was issued: every change above is a new row under DEDUP UPSERT KEYS(ts, tag).

A delete is not resurrected by an outbox redelivery

This was proven with a real replay, not a simulation:

  1. 07:47:26–07:47:35: docker stop QuestDB. The Primary (central-1) kept capturing; its writes failed, so the entries stayed pending in its outbox.
  2. 07:47:35: the outbox was snapshotted while QuestDB was down (commit point commit.1303.0).
  3. 07:47:35: QuestDB was restarted. The 16-value backlog (476…491) drained as one batch (server_ts 07:47:41.620267), with no gap. This is a second result: QuestDB loss is ridden out by the outbox.
  4. 07:50:45–46: delete-at-time on two backlog rows, 07:47:28.950591 (479) and 07:47:31.949216 (482). Both became tombstones (deleted=true, 0x809B0000).
  5. 07:50:46: central-1 was stopped. Its outbox directory (on the otopcua-localdb-central-1 volume) was replaced with the pre-delivery snapshot.
  6. 07:51:15: central-1 was started. It re-drained the snapshot's entries, and the outbox commit point advanced 1303 → 1328.

After the replay:

  • Both tombstones are unchanged: same server_ts 07:50:45.669146 / 07:50:46.074579, still deleted=true.
  • Every other row in the window kept its original server_ts 07:47:41.620267, so nothing was re-written.
  • 24 rows over 12 keys (2 tags × 12): no duplicates.
  • historyread 07:47:27–07:47:33 returns 478, 480, 481, 483; 479 and 482 stay deleted.

A first attempt used ALTER TABLE hist_sample SUSPEND WAL plus a SIGKILL of the Primary. It could not produce a redelivery. The writer deliberately treats a suspended table as committed and acknowledges it (R5: rows committed to the WAL become visible later, and are not re-sent). It logged "QuestDB table hist_sample is suspended (writerTxn 327 < sequencerTxn 337); not waiting" and acked. That attempt exposed the crash-failover finding below.

4. Failover

  • 07:50:46: central-1 was stopped (step 5 above). Central-2 logged "now the recording Primary" at 07:50:46.
  • 07:51:57: docker stop central-2, then the Primary. Central-1 logged "this node is now the recording Primary … resuming value capture" at 07:51:57, as central-2 began leaving.
  • 07:52:13: central-2 was restarted and rejoined as standby ("not the recording Primary"). Its outbox hlog.log.0 stayed frozen at 57856 bytes (mtime 07:51:58). Central-1's grew from 65536 to 84480.
  • Rate across both failovers was 1×. Per-30 s FastUInt1 counts from 07:50:00 to 07:54:30: 30, 29, 30, 30, 30, 30, 29, 29, 30.
    • There was no gap at the boundary: 743…754 are contiguous across 07:51:57.
    • There was no doubling: 267 rows over 267 distinct timestamps.

5. Device loss: driver Bad sample and comms-loss outage marker

This leg ran on Modbus (HR5). otopcua-pymodbus-standard was stopped at 07:54:40 and restarted at 07:56:51.

ts kind value status server_ts
07:51:18.715101 2 5 0 07:51:18
07:54:51.960244 0 (Empty) NULL 0x80050000 BadCommunicationError (the driver's own Bad publish) 07:56:13
07:56:48.652185 0 (Empty) NULL 0x80310000 BadNoCommunication (the #527 watchdog outage marker) 07:56:48
07:56:58.688150 2 5 0 (recovery re-publish) 07:56:58

Reads over the outage:

  • Raw historyread 07:50–07:58 shows Good, Bad, Bad, Good.
  • Average at 120 s, 07:52–07:58, gives (null) Bad / (null) Bad / 5 Uncertain. The outage is visible and is not bridged.

The Bad sample's server_ts is 82 s after its source time. Its source time is the driver's failed-read stamp; it reached the recorder later. Its position in the series is correct either way, because ordering and reads key on source time.

6. TTL visible in table metadata

Both centrals were recreated with OTOPCUA_HISTORIAN_QUESTDB_RETENTION_DAYS=30. At 07:57:41 the bootstrapper logged Applied TTL 30 day(s) to QuestDB table hist_sample. and the same for hist_event. The TTL was applied to the already existing tables.

tables() before and after:

table before after
hist_event 0 HOUR 30 DAY
hist_sample 0 HOUR 30 DAY
hist_tag 0 HOUR 0 HOUR (no TTL on the tag catalog, by design)

SHOW CREATE TABLE hist_sample: … timestamp(ts) PARTITION BY DAY TTL 30 DAYS DEDUP UPSERT KEYS(ts,tag);

Recording resumed after the restart: 57 FastUInt1 rows and 56 FastLabel rows in the first minute.

Gate findings

  1. A crash failover leaves a recording gap of about 30 s. This is backend-independent and predates this work.
    • What happened: after docker kill (SIGKILL) of the recording Primary at 07:45:58, the next FastUInt1 row is at 07:46:29. Central-1 became the recording Primary only at 07:46:30, when the killed node rejoined as a new incarnation.
    • Why: #537 gates capture to the Primary. A crashed Primary stays unreachable but not yet downed for the Akka failure-detector window plus auto-down-unreachable-after = 15s, so no node captures during that time.
    • Contrast: a clean docker stop hands over at once (leg 4). The SQL Server gate only exercised the clean path.
    • Status: proposed follow-up issue, not fixed here.
  2. Cannot load library libgssapi_krb5.so.2 is printed once per central boot. It does not appear on the site nodes, which have neither a ConfigDb nor a QuestDB client. It is most likely Npgsql's default GSS-encryption probe, which falls back cleanly. Everything worked. If it is confirmed as Npgsql, GSS Encryption Mode=Disable in the connection string silences it.

Restore

  • The rig was restored afterwards:
    • central-1 and central-2 were recreated with the compose defaults (historian off, Backend=Gateway).
    • The gate tag, script, UNS reference, API keys and ACL rows were removed.
    • The HR5 and FastUInt1 TagConfigs were reverted.
    • The configuration was redeployed.
    • The overlay questdb container was stopped and removed; the otopcua-questdb-data volume was kept.
    • The opc-plc and pymodbus fixtures were stopped (normally down).
  • The compose keys stay: Backend defaults to Gateway, and RetentionDays defaults to empty.