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

OpcUaClient session loss (#670) follow-ups: TCP-stall proxy test, ReconnectPeriod field, recovery latency, drop observability #676

New Issue
Closed
opened 2026-10-11 10:18:14 -04:00 by dohertj2 · 1 comment
dohertj2 commented 2026-10-11 10:18:14 -04:00
Owner
Copy Link
Copy Source

Follow-ups from #670 (OpcUaClient session loss).

  1. The in-place blip (session survives, keep-alives fail, then recover) has no automated test — needs a TCP-stall proxy fixture. It is covered only by the live gate (docker pause of opc-plc).
  2. AdminUI still shows the now-unused OpcUaClient ReconnectPeriod field (the SDK SessionReconnectHandler is deleted) — remove it.
  3. Recovery after a real upstream restart (session lost) now waits for the #527 watchdog (~90–106 s). Consider a faster driver-initiated re-init once a session is definitively gone.
  4. Observability: Serilog__MinimumLevel__* env overrides produced no Debug lines on the docker-dev rig, and stale_notification_dropped is OTel-only, so replay-guard drops were unobservable on the rig. Fix the log-level override path or add an Information-level per-recovery drop summary.
  5. Behaviour to know: inside the post-recovery window, a notification with a source timestamp equal to an accepted one is dropped (a status-only change that keeps the old source timestamp would be lost during the window only).
Follow-ups from #670 (OpcUaClient session loss). 1. The in-place blip (session survives, keep-alives fail, then recover) has no automated test — needs a TCP-stall proxy fixture. It is covered only by the live gate (`docker pause` of opc-plc). 2. AdminUI still shows the now-unused OpcUaClient `ReconnectPeriod` field (the SDK `SessionReconnectHandler` is deleted) — remove it. 3. Recovery after a real upstream restart (session lost) now waits for the #527 watchdog (~90–106 s). Consider a faster driver-initiated re-init once a session is definitively gone. 4. Observability: `Serilog__MinimumLevel__*` env overrides produced no Debug lines on the docker-dev rig, and `stale_notification_dropped` is OTel-only, so replay-guard drops were unobservable on the rig. Fix the log-level override path or add an Information-level per-recovery drop summary. 5. Behaviour to know: inside the post-recovery window, a notification with a source timestamp equal to an accepted one is dropped (a status-only change that keeps the old source timestamp would be lost during the window only).
dohertj2 commented 2026-10-11 13:20:32 -04:00
Author
Owner
Copy Link
Copy Source

Done — merged to master (50c09e21, live-gate fix 6d5c1c76).

  1. In-place blip test: new TcpStallProxy + OpcUaClientDriverStallWireTests (in-process server): stall → one BadNoCommunication, frozen LastSuccessfulRead → resume ⇒ same session, Healthy, value republished Good, later change arrives, no source-timestamp regression (waits for the SDK's late backlog flush so the check can't pass vacuously). It needed a driver fix first: the driver now rewrites the advertised endpoint's host and port to the configured URL (SDK SelectEndpoint behaviour; port kept when the URL has none) — also fixes upstreams behind NAT/port maps. The test also found a real defect, fixed: a value change riding a Publish in flight across the stall was lost for good; a trailing re-read Timeout + KeepAliveInterval after an in-place recovery repairs it (incl. Good→Bad), serialized with live delivery by a per-ref delivery sequence so it can never land an older value over a newer one.
  2. ReconnectPeriod removed everywhere (options, AdminUI form, docs, tests); stored JSON carrying it still parses (factory, probe, browser).
  3. Fast recovery: new opt-in IDriverConnectionLossSource (Core.Abstractions). OpcUaClient raises it once per session on a definitive loss — session statuses, BadServerHalted, a server-reported subscription loss, or a sustained closed secure channel (2nd consecutive BadSecureChannelClosed/BadConnectionClosed keep-alive failure: reproduced in-process, the SDK never reopens a closed channel once the reconnect handler is gone). DriverInstanceActor turns it into an immediate re-initialise while Connected. Ambiguous stall statuses (BadNoCommunication, BadRequestTimeout) and the publishing-stall heuristic still go through the #527 watchdog.
  4. Replay-guard summary at Information when drops > 0 ("dropped N late notifications across M refs after recovery"). Separately: docker-dev/docker-compose.debug.yml raises per-category levels (verified to reach actor Debug lines); the earlier "env override doesn't work" was operational, not a code defect.
  5. Equal-timestamp drop inside the replay window documented (the trailing re-read repairs a status-only change).

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

  • livegate-5 A1 failed at 50c09e21: a real process stop yields BadSecureChannelClosed → BadConnectionClosed, not on the definitive list ⇒ still ~122 s. Fixed in 6d5c1c76.
  • livegate-7 (re-gate, 6d5c1c76) PASS: docker restart ×2 ⇒ first Good 12.9 s / 14.2 s (was ~122 s); SIGINT stop ⇒ ConnectionLost in 7 s, Good ~27 s after the server came back (opc-plc boot + one reconnect interval); docker kill ⇒ ConnectionLost in 5 s, Good ~25 s after restart (was 98–127 s). docker pause blips (2×2, 20 s) still recover in place (no ConnectionLost, no re-init): one BadNoCommunication per outage per node, 0 regressions/equal repeats, summary line on all 8. One re-init per outage, watchdog never fired.

Known gap (documented): a definitive loss raised while the actor is not Connected (e.g. during init) is not deferred — that session falls back to the watchdog.

Done — merged to master (`50c09e21`, live-gate fix `6d5c1c76`). 1. **In-place blip test:** new `TcpStallProxy` + `OpcUaClientDriverStallWireTests` (in-process server): stall → one `BadNoCommunication`, frozen `LastSuccessfulRead` → resume ⇒ same session, Healthy, value republished Good, later change arrives, no source-timestamp regression (waits for the SDK's late backlog flush so the check can't pass vacuously). It needed a driver fix first: **the driver now rewrites the advertised endpoint's host and port** to the configured URL (SDK `SelectEndpoint` behaviour; port kept when the URL has none) — also fixes upstreams behind NAT/port maps. The test also found a real defect, fixed: a value change riding a Publish in flight across the stall was lost for good; a **trailing re-read** `Timeout + KeepAliveInterval` after an in-place recovery repairs it (incl. Good→Bad), serialized with live delivery by a per-ref delivery sequence so it can never land an older value over a newer one. 2. `ReconnectPeriod` removed everywhere (options, AdminUI form, docs, tests); stored JSON carrying it still parses (factory, probe, browser). 3. **Fast recovery:** new opt-in `IDriverConnectionLossSource` (Core.Abstractions). OpcUaClient raises it once per session on a **definitive** loss — session statuses, `BadServerHalted`, a server-reported subscription loss, or a **sustained closed secure channel** (2nd consecutive `BadSecureChannelClosed`/`BadConnectionClosed` keep-alive failure: reproduced in-process, the SDK never reopens a closed channel once the reconnect handler is gone). `DriverInstanceActor` turns it into an immediate re-initialise while Connected. Ambiguous stall statuses (`BadNoCommunication`, `BadRequestTimeout`) and the publishing-stall heuristic still go through the #527 watchdog. 4. Replay-guard summary at Information when drops > 0 ("dropped N late notifications across M refs after recovery"). Separately: `docker-dev/docker-compose.debug.yml` raises per-category levels (verified to reach actor Debug lines); the earlier "env override doesn't work" was operational, not a code defect. 5. Equal-timestamp drop inside the replay window documented (the trailing re-read repairs a status-only change). **Live gates (docker-dev, opc-plc):** - livegate-5 A1 **failed** at `50c09e21`: a real process stop yields `BadSecureChannelClosed` → `BadConnectionClosed`, not on the definitive list ⇒ still ~122 s. Fixed in `6d5c1c76`. - livegate-7 (re-gate, `6d5c1c76`) **PASS**: `docker restart` ×2 ⇒ first Good 12.9 s / 14.2 s (was ~122 s); SIGINT stop ⇒ ConnectionLost in 7 s, Good ~27 s after the server came back (opc-plc boot + one reconnect interval); `docker kill` ⇒ ConnectionLost in 5 s, Good ~25 s after restart (was 98–127 s). `docker pause` blips (2×2, 20 s) still recover **in place** (no ConnectionLost, no re-init): one `BadNoCommunication` per outage per node, **0** regressions/equal repeats, summary line on all 8. One re-init per outage, watchdog never fired. Known gap (documented): a definitive loss raised while the actor is not Connected (e.g. during init) is not deferred — that session falls back to the watchdog.
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#676
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?