dohertj2/lmxopcua
1
0
Fork 0
Code Issues 14 Pull Requests Actions Packages Projects Releases Wiki Activity

OpcUaClient driver: upstream session loss never goes Bad and never recovers (live-gate find) #670

New Issue
Closed
opened 2026-10-09 15:26:04 -04:00 by dohertj2 · 1 comment
dohertj2 commented 2026-10-09 15:26:04 -04:00
Owner
Copy Link
Copy Source

Found by the pluggable-historian live gate on docker-dev (2026-10-09, docs/plans/2026-10-09-pluggable-historian-live-gate.md §5). This bug predates that work.

Repro:

  1. On the docker-dev rig, cluster MAIN, driver opcplc (OpcUaClient → opc.tcp://10.100.0.35:50000), tag opcplc/plc/FastUInt1, run docker stop otopcua-opc-plc on 10.100.0.35.
  2. The node keeps serving the last value (745) with status Good for more than 3.5 minutes.
  3. No Bad publish happens, driver health is unaffected, and the #527 comms-loss watchdog never trips.
  4. After docker start otopcua-opc-plc, the node stays frozen at 745 Good and does not recover.

The same procedure with Modbus behaves correctly: BadCommunicationError, then a BadNoCommunication outage marker about 90 s later, then recovery.

Expected:

  • A lost session (keep-alive failure or a closed channel) publishes Bad for every subscribed ref and drives health to non-Healthy with LastSuccessfulRead frozen, so #527 can reconnect.
  • After the upstream server returns, the driver resubscribes and re-publishes.

Check the SDK KeepAlive and SessionReconnectHandler wiring in the OpcUaClient driver, and whether a reconnect re-creates the subscriptions.

Claude-Session: https://claude.ai/code/session_01Ef2ozxS7QPanGT8uoATbTe

Found by the pluggable-historian live gate on docker-dev (2026-10-09, `docs/plans/2026-10-09-pluggable-historian-live-gate.md` §5). This bug predates that work. **Repro:** 1. On the docker-dev rig, cluster MAIN, driver `opcplc` (OpcUaClient → `opc.tcp://10.100.0.35:50000`), tag `opcplc/plc/FastUInt1`, run `docker stop otopcua-opc-plc` on 10.100.0.35. 2. The node keeps serving the last value (`745`) with status **Good** for more than 3.5 minutes. 3. No Bad publish happens, driver health is unaffected, and the #527 comms-loss watchdog never trips. 4. After `docker start otopcua-opc-plc`, the node stays frozen at `745` Good and does not recover. The same procedure with Modbus behaves correctly: BadCommunicationError, then a BadNoCommunication outage marker about 90 s later, then recovery. **Expected:** - A lost session (keep-alive failure or a closed channel) publishes Bad for every subscribed ref and drives health to non-Healthy with `LastSuccessfulRead` frozen, so #527 can reconnect. - After the upstream server returns, the driver resubscribes and re-publishes. Check the SDK `KeepAlive` and `SessionReconnectHandler` wiring in the OpcUaClient driver, and whether a reconnect re-creates the subscriptions. Claude-Session: https://claude.ai/code/session_01Ef2ozxS7QPanGT8uoATbTe
dohertj2 commented 2026-10-11 10:17:59 -04:00
Author
Owner
Copy Link
Copy Source

Fixed in db6446ce, with live-gate fixes 69987104 (F1/F2) and bc03adb1 (R2) — all merged to master.

What changed in OpcUaClientDriver

  • A bad session keep-alive ⇒ health Degraded (LastSuccessfulRead preserved) + one BadNoCommunication per subscribed ref per outage (value retained server-side, stamped at detection time) + a quality-only alarm update. It used to stay Healthy forever.
  • Good keep-alives and notifications advance LastSuccessfulRead, so the #527 comms-loss watchdog now trips on sustained loss — its shutdown + init + resubscribe is the recovery.
  • The SDK SessionReconnectHandler is deleted (it retried forever and, on a session recreate, cloned subscriptions the driver no longer tracked). A lost subscription (BadNoSubscription / PublishingStopped) on a live session is detected too; recovery is tied to the captured session; UpdateHealth uses a CAS loop.
  • A same-session recovery re-reads and republishes Good (beats the (value,status) dedup), and arms a replay guard for max(30 s, 2 × keep-alive window): each ref drops any notification whose source time is ≤ the newest it has accepted, for the whole window; expiry disarms entirely (no global monotonic rule — an upstream clock step-back is not frozen). Counter stale_notification_dropped.
  • SDK logging forwarded at Warning (rate-limited) via SdkTelemetry.ForLogger.

Live gates (docker-dev, opc-plc fixture)

  • Gate 1: Degraded + Bad on loss, watchdog recovery, Good republish. Found F1 (the outage Bad was not historized — timestamp collision with the last Good) and F2 (a late, older notification was published after recovery).
  • Gate 2: F1 PASS on SqlServer and QuestDB, docker stop and docker pause. F2 FAIL (R2) — the guard disarmed on the first fresh notification, before the SDK's replay arrived 4–6 s later.
  • Gate 4 (re-gate of R2 at bc03adb1): PASS — 4 runs × 2 pause blips (20–30 s), raw subscriptions on both centrals: 1,728 notifications, 0 older or equal source timestamps (gate 2 saw ~3 regressions per node per run), first Good within ~1 s of unpause, continuous delivery through 75 s after each recovery, exactly one BadNoCommunication per outage per node.

Follow-ups filed (TCP-stall proxy test, unused AdminUI ReconnectPeriod, watchdog-bound recovery after an upstream restart, drop observability on the rig).

Fixed in `db6446ce`, with live-gate fixes `69987104` (F1/F2) and `bc03adb1` (R2) — all merged to master. **What changed in `OpcUaClientDriver`** - A bad session keep-alive ⇒ health `Degraded` (`LastSuccessfulRead` preserved) + **one `BadNoCommunication` per subscribed ref per outage** (value retained server-side, stamped at detection time) + a quality-only alarm update. It used to stay `Healthy` forever. - Good keep-alives and notifications advance `LastSuccessfulRead`, so the #527 comms-loss watchdog now trips on sustained loss — its shutdown + init + resubscribe is the recovery. - The SDK `SessionReconnectHandler` is deleted (it retried forever and, on a session recreate, cloned subscriptions the driver no longer tracked). A lost subscription (`BadNoSubscription` / `PublishingStopped`) on a live session is detected too; recovery is tied to the captured session; `UpdateHealth` uses a CAS loop. - A same-session recovery re-reads and republishes Good (beats the (value,status) dedup), and arms a **replay guard** for max(30 s, 2 × keep-alive window): each ref drops any notification whose source time is ≤ the newest it has accepted, for the whole window; expiry disarms entirely (no global monotonic rule — an upstream clock step-back is not frozen). Counter `stale_notification_dropped`. - SDK logging forwarded at Warning (rate-limited) via `SdkTelemetry.ForLogger`. **Live gates (docker-dev, opc-plc fixture)** - Gate 1: Degraded + Bad on loss, watchdog recovery, Good republish. Found **F1** (the outage Bad was not historized — timestamp collision with the last Good) and **F2** (a late, older notification was published after recovery). - Gate 2: F1 **PASS** on SqlServer and QuestDB, `docker stop` and `docker pause`. F2 **FAIL** (R2) — the guard disarmed on the first fresh notification, before the SDK's replay arrived 4–6 s later. - Gate 4 (re-gate of R2 at `bc03adb1`): **PASS** — 4 runs × 2 pause blips (20–30 s), raw subscriptions on both centrals: 1,728 notifications, **0** older or equal source timestamps (gate 2 saw ~3 regressions per node per run), first Good within ~1 s of unpause, continuous delivery through 75 s after each recovery, exactly one `BadNoCommunication` per outage per node. Follow-ups filed (TCP-stall proxy test, unused AdminUI `ReconnectPeriod`, watchdog-bound recovery after an upstream restart, drop observability on the rig).
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
auto-managed
queue management
 cross-driver
queue management
 driver/abcip
queue management
 driver/ablegacy
queue management
 driver/focas
queue management
 driver/mqtt
MQTT / Sparkplug B broker-subscribe driver
 driver/opcuaclient
queue management
 driver/s7
queue management
 driver/twincat
queue management
 phase/1
queue management
 phase/2
queue management
 phase/3
queue management
 phase/4
queue management
 phase/5
queue management
 phase/6
queue management
 queue/blocked
queue management
 queue/done
queue management
 queue/failed
queue management
 queue/in-progress
queue management
 queue/queued
queue management
No Label
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
dohertj2 (dohertj2)
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: dohertj2/lmxopcua#670
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?