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

DriverInstanceActor.DisconnectObserved has no production sender — a driver whose device dies mid-run is never detected, never reconnects, and never reports comms loss #527

New Issue
Closed
opened 2026-07-31 09:54:31 -04:00 by dohertj2 · 1 comment
dohertj2 commented 2026-07-31 09:54:31 -04:00
Owner
Copy Link
Copy Source

Found while running the #481 live gate on docker-dev. This is a pre-existing defect, not a regression from #481, but it makes #477 Layer 2 and #481 Layer 4 unreachable in the scenario both were written for.

What is true today

DriverInstanceActor.DisconnectObserved is never sent by anything in src/ — the only senders in the tree are four test files. The three paths into the Reconnecting state are therefore:

  1. InitializeFailed while Connecting — the driver never connected in the first place;
  2. DisconnectObserved — no production sender;
  3. ForceReconnect — an operator clicking Reconnect.

So for a driver that is already Connected, nothing transitions it out. PublishHealthSnapshot does call _driver.GetHealth(), but only to publish a status snapshot — it never acts on a driver that reports itself unhealthy.

Live evidence (docker-dev, 2026-07-31)

Seeded Modbus driver MAIN-modbus against the otopcua-pymodbus-standard fixture, connected and polling Good.

  • docker pause the fixture -> the driver keeps publishing per-tag 0x80050000 (BadCommunicationError). Stays Connected. No disconnect observed log line, no ConnectivityChanged.
  • docker stop the fixture -> identical. Waited >10 minutes. Still Connected, still publishing Bad.
  • docker start the fixture -> the driver did not recover. Tag stayed Bad for ~5 more minutes while a second Modbus driver against a different fixture (rtu-gate/Device1/HR200) read Good throughout, ruling out anything server-wide.
  • Restart the node -> Good immediately (Value: 2, Status: 0x00000000).

The socket is dead, the poll loop fails forever, and nothing re-initializes it.

Why this matters beyond the recovery bug

Both condition-Quality comms-loss paths hang off ConnectivityChanged:

  • #477 Layer 2 — DriverHostActor.OnDriverConnectivityChanged annotates every native condition the driver owns Bad. Never fires for a mid-run device loss.
  • #481 Layer 4 — FanCommsLossToDependencyMux pushes Bad into the dependency mux for scripted alarms. Same.

Both are correctly wired to the signal; the signal just never arrives for the case their issues describe ("a poll driver whose device goes unreachable emits only ConnectivityChanged(false)" — it does not emit it at all). #481's unit tests drive the message directly and are unaffected.

Partial mitigation that already exists: Modbus publishes Bad per tag on poll failure, so #478 Layer 3 does carry Bad into scripted-alarm input quality for this driver. That is not general — it depends on each driver choosing to publish Bad rather than go silent, and it does nothing for the native-condition path or for recovery.

What a fix probably looks like

The driver-side signal already exists and is already read: IDriver.GetHealth() returns DriverState.Reconnecting / Faulted. The smallest honest fix is for the Connected-state HealthPollTick — which already calls GetHealth() and already runs ReconcileSubscription() — to also self-Tell DisconnectObserved when the driver reports itself non-Healthy for N consecutive polls. That reuses the existing retry/backoff machinery in Reconnecting and gets recovery, ConnectivityChanged, and both quality paths in one change.

Worth checking per driver whether GetHealth() actually goes non-Healthy on sustained read failure before relying on it — that is the load-bearing assumption, and #517 already found one driver (CalculationDriver) hard-coding Healthy.

Acceptance

  • A connected driver whose device dies transitions to Reconnecting and emits ConnectivityChanged(false).
  • It re-initializes and recovers on its own when the device returns — no node restart.
  • Live-gated on docker-dev with the Modbus fixture: stop -> condition Quality Bad on the wire; start -> values Good again without restarting the node.
Found while running the #481 live gate on docker-dev. This is a pre-existing defect, not a regression from #481, but it makes #477 Layer 2 and #481 Layer 4 unreachable in the scenario both were written for. ## What is true today `DriverInstanceActor.DisconnectObserved` is **never sent by anything in `src/`** — the only senders in the tree are four test files. The three paths into the `Reconnecting` state are therefore: 1. `InitializeFailed` while *Connecting* — the driver never connected in the first place; 2. `DisconnectObserved` — **no production sender**; 3. `ForceReconnect` — an operator clicking Reconnect. So for a driver that is **already Connected**, nothing transitions it out. `PublishHealthSnapshot` does call `_driver.GetHealth()`, but only to publish a status snapshot — it never acts on a driver that reports itself unhealthy. ## Live evidence (docker-dev, 2026-07-31) Seeded Modbus driver `MAIN-modbus` against the `otopcua-pymodbus-standard` fixture, connected and polling Good. - `docker pause` the fixture -> the driver keeps publishing per-tag `0x80050000` (BadCommunicationError). Stays **Connected**. No `disconnect observed` log line, no `ConnectivityChanged`. - `docker stop` the fixture -> identical. Waited >10 minutes. Still Connected, still publishing Bad. - `docker start` the fixture -> **the driver did not recover.** Tag stayed Bad for ~5 more minutes while a second Modbus driver against a different fixture (`rtu-gate/Device1/HR200`) read Good throughout, ruling out anything server-wide. - Restart the node -> Good immediately (`Value: 2, Status: 0x00000000`). The socket is dead, the poll loop fails forever, and nothing re-initializes it. ## Why this matters beyond the recovery bug Both condition-Quality comms-loss paths hang off `ConnectivityChanged`: - **#477 Layer 2** — `DriverHostActor.OnDriverConnectivityChanged` annotates every native condition the driver owns Bad. Never fires for a mid-run device loss. - **#481 Layer 4** — `FanCommsLossToDependencyMux` pushes Bad into the dependency mux for scripted alarms. Same. Both are correctly wired to the signal; the signal just never arrives for the case their issues describe ("a poll driver whose device goes unreachable emits only `ConnectivityChanged(false)`" — it does not emit it at all). #481's unit tests drive the message directly and are unaffected. Partial mitigation that already exists: Modbus publishes Bad **per tag** on poll failure, so #478 Layer 3 does carry Bad into scripted-alarm input quality for this driver. That is not general — it depends on each driver choosing to publish Bad rather than go silent, and it does nothing for the native-condition path or for recovery. ## What a fix probably looks like The driver-side signal already exists and is already read: `IDriver.GetHealth()` returns `DriverState.Reconnecting` / `Faulted`. The smallest honest fix is for the Connected-state `HealthPollTick` — which already calls `GetHealth()` and already runs `ReconcileSubscription()` — to also self-`Tell` `DisconnectObserved` when the driver reports itself non-Healthy for N consecutive polls. That reuses the existing retry/backoff machinery in `Reconnecting` and gets recovery, `ConnectivityChanged`, and both quality paths in one change. Worth checking per driver whether `GetHealth()` actually goes non-Healthy on sustained read failure before relying on it — that is the load-bearing assumption, and #517 already found one driver (`CalculationDriver`) hard-coding `Healthy`. ## Acceptance - A connected driver whose device dies transitions to Reconnecting and emits `ConnectivityChanged(false)`. - It re-initializes and recovers on its own when the device returns — no node restart. - Live-gated on docker-dev with the Modbus fixture: stop -> condition Quality Bad on the wire; start -> values Good again without restarting the node.
dohertj2 commented 2026-07-31 10:59:17 -04:00
Author
Owner
Copy Link
Copy Source

Fixed and merged as 916f0f79 (feature commit 5a7a08de). Live gate PASSED, run twice.

What changed

The Connected health tick now evaluates a comms-loss watchdog and self-sends DisconnectObserved. GetHealth() went from reporting-only to load-bearing.

The issue's proposed trip condition is wrong, and this is the substantive correction

This issue suggested tripping when the driver "reports itself non-Healthy for N consecutive polls". That would have caused a worse regression than the bug.

DriverState.Degraded means connected but some data is bad — the enum's own doc says so. Several drivers publish health per tag inside their read loop: ModbusDriver.ReadAsync writes Healthy or Degraded once per reference, so a single unreadable address leaves the driver latched Degraded whenever it happens to be read last — indefinitely, against a device that is perfectly reachable. A state-only watchdog would tear that driver down every 90 s forever.

The implemented trip condition is a conjunction:

  1. state is not Healthy, and
  2. DriverHealth.LastSuccessfulRead has not advanced for 90 s (measured from the Connected entry when the driver has never reported a successful read).

LastSuccessfulRead is the honest liveness evidence — every driver advances it on any success and preserves it across Degraded/Faulted writes, so one bad tag among good ones keeps it moving while a genuinely dead device freezes it. The state check stays as the second conjunct because a Healthy driver with nothing subscribed legitimately never reads and must not be declared dead for being idle.

Each conjunct has a test that goes red when the other is deleted, so neither is redundant.

The load-bearing assumption, checked

The issue flagged it, so all 12 drivers were surveyed rather than assumed: nine poll drivers reach Degraded on sustained failure, MQTT derives Reconnecting/Faulted from its live connection state, Galaxy reports Degraded via its reconnect supervisor. CalculationDriver reports Healthy while running and therefore can never trip — correct, since it has no transport to reconnect to.

Worth noting: OpcUaClientDriver's reconnect-exhausted branch already carried the comment "the Core never learns it must offer an operator reinitialize". It was written against a mechanism that did not exist. It does now.

A second defect found while fixing this

The Reconnecting retry now calls ShutdownAsync before InitializeAsync. ModbusDriver (_transport) and MqttDriver (_connection) overwrite an IAsyncDisposable field inside InitializeAsync without disposing the previous one, so re-initialising without a teardown leaks a socket per attempt. That was latent while only a manual Force Reconnect reached the path — this fix makes it automatic and unbounded, so a device down for an hour would have leaked ~360 transports at the 10 s retry interval.

Verification

8 new tests in DriverInstanceActorCommsLossWatchdogTests. Every absence assertion carries a positive control (a proven count of processed health-poll ticks), so none can pass merely because nothing ran. Falsified five ways — dropping either conjunct reds exactly the test written for it; removing the teardown, the null baseline, or the watchdog call each reds its own guard.

Full suite green apart from 3 Host.IntegrationTests failures verified failing identically on clean master in a separate worktree (PrimaryGateFailoverTests.Delivered_redundancy_snapshot_drives_the_primary_write_gate_across_the_cluster, DriverProbeHandshakeE2eTests.AbCip_Green_AgainstSim, DriverProbeRegistrationTests.AddOtOpcUaDriverProbes_is_idempotent).

Live gate — docker-dev, Modbus MAIN-modbus vs otopcua-pymodbus-standard

Baseline: raw ns=2;s=pymodbus/plc/HR200X and UNS ns=3;s=gate481/line1/press1/hr200 both Good.

14:51:41  fixture docker stop
14:53:28  WRN DriverInstance MAIN-modbus: no successful read for 00:01:49 while
              reporting Degraded (Transport not connected) - declaring comms lost
14:53:28  WRN DriverInstance MAIN-modbus: disconnect observed; reconnecting
14:53:43  fixture docker start
14:53:48  INF DriverInstance MAIN-modbus: reconnected
14:53:48  INF DriverInstance MAIN-modbus: subscribed to 2 refs (poll-sub-2)

Both NodeIds read Good with fresh timestamps immediately after — no node restart, which is precisely what the original repro required.

Re-run at Debug to observe the consumers rather than infer them:

14:57:21  WRN ... declaring comms lost and reconnecting
14:57:21  DBG DriverHost central-1:4053: driver MAIN-modbus disconnected -
              pushed BadNoCommunication for 2 mux ref(s)          <- #481 Layer 4
14:57:21  DBG DriverHost ...: driver DRV-opcua1 disconnected -
              annotated 1 native condition(s) 0x80310000          <- #477 Layer 2

(The annotated line appears for DRV-opcua1 rather than MAIN-modbus because only that driver owns native conditions; it is the same handler.) So both quality paths this issue reported as unreachable are now reached.

The one clause not asserted on the wire is condition Quality itself — Client.CLI has no select clause for it in its alarm event filter and its read throws on a Bad DataValue before printing. That is a CLI observability gap, not a gap in this fix; the fan-out is observed one layer in.

Docs: docs/DriverLifecycle.md §"The comms-loss watchdog", docs/AlarmTracking.md (stale caveat replaced), and CLAUDE.md.

Fixed and merged as `916f0f79` (feature commit `5a7a08de`). **Live gate PASSED**, run twice. ## What changed The `Connected` health tick now evaluates a comms-loss watchdog and self-sends `DisconnectObserved`. `GetHealth()` went from reporting-only to load-bearing. ## The issue's proposed trip condition is wrong, and this is the substantive correction This issue suggested tripping when the driver "reports itself non-Healthy for N consecutive polls". That would have caused a worse regression than the bug. `DriverState.Degraded` means *connected but some data is bad* — the enum's own doc says so. Several drivers publish health **per tag inside their read loop**: `ModbusDriver.ReadAsync` writes `Healthy` or `Degraded` once per reference, so a single unreadable address leaves the driver latched `Degraded` whenever it happens to be read last — indefinitely, against a device that is perfectly reachable. A state-only watchdog would tear that driver down every 90 s forever. The implemented trip condition is a **conjunction**: 1. state is not `Healthy`, **and** 2. `DriverHealth.LastSuccessfulRead` has not advanced for 90 s (measured from the Connected entry when the driver has never reported a successful read). `LastSuccessfulRead` is the honest liveness evidence — every driver advances it on any success and *preserves* it across `Degraded`/`Faulted` writes, so one bad tag among good ones keeps it moving while a genuinely dead device freezes it. The state check stays as the second conjunct because a `Healthy` driver with nothing subscribed legitimately never reads and must not be declared dead for being idle. Each conjunct has a test that goes red when the **other** is deleted, so neither is redundant. ## The load-bearing assumption, checked The issue flagged it, so all 12 drivers were surveyed rather than assumed: nine poll drivers reach `Degraded` on sustained failure, MQTT derives `Reconnecting`/`Faulted` from its live connection state, Galaxy reports `Degraded` via its reconnect supervisor. `CalculationDriver` reports `Healthy` while running and therefore can never trip — correct, since it has no transport to reconnect to. Worth noting: `OpcUaClientDriver`'s reconnect-exhausted branch already carried the comment *"the Core never learns it must offer an operator reinitialize"*. It was written against a mechanism that did not exist. It does now. ## A second defect found while fixing this The `Reconnecting` retry now calls `ShutdownAsync` before `InitializeAsync`. `ModbusDriver` (`_transport`) and `MqttDriver` (`_connection`) **overwrite an `IAsyncDisposable` field inside `InitializeAsync` without disposing the previous one**, so re-initialising without a teardown leaks a socket per attempt. That was latent while only a manual Force Reconnect reached the path — this fix makes it automatic and unbounded, so a device down for an hour would have leaked ~360 transports at the 10 s retry interval. ## Verification 8 new tests in `DriverInstanceActorCommsLossWatchdogTests`. Every absence assertion carries a positive control (a proven count of processed health-poll ticks), so none can pass merely because nothing ran. Falsified five ways — dropping either conjunct reds exactly the test written for it; removing the teardown, the null baseline, or the watchdog call each reds its own guard. Full suite green apart from 3 `Host.IntegrationTests` failures verified failing identically on clean `master` in a separate worktree (`PrimaryGateFailoverTests.Delivered_redundancy_snapshot_drives_the_primary_write_gate_across_the_cluster`, `DriverProbeHandshakeE2eTests.AbCip_Green_AgainstSim`, `DriverProbeRegistrationTests.AddOtOpcUaDriverProbes_is_idempotent`). ### Live gate — docker-dev, Modbus `MAIN-modbus` vs `otopcua-pymodbus-standard` Baseline: raw `ns=2;s=pymodbus/plc/HR200X` and UNS `ns=3;s=gate481/line1/press1/hr200` both Good. ``` 14:51:41 fixture docker stop 14:53:28 WRN DriverInstance MAIN-modbus: no successful read for 00:01:49 while reporting Degraded (Transport not connected) - declaring comms lost 14:53:28 WRN DriverInstance MAIN-modbus: disconnect observed; reconnecting 14:53:43 fixture docker start 14:53:48 INF DriverInstance MAIN-modbus: reconnected 14:53:48 INF DriverInstance MAIN-modbus: subscribed to 2 refs (poll-sub-2) ``` Both NodeIds read Good with fresh timestamps immediately after — **no node restart**, which is precisely what the original repro required. Re-run at Debug to observe the consumers rather than infer them: ``` 14:57:21 WRN ... declaring comms lost and reconnecting 14:57:21 DBG DriverHost central-1:4053: driver MAIN-modbus disconnected - pushed BadNoCommunication for 2 mux ref(s) <- #481 Layer 4 14:57:21 DBG DriverHost ...: driver DRV-opcua1 disconnected - annotated 1 native condition(s) 0x80310000 <- #477 Layer 2 ``` (The `annotated` line appears for `DRV-opcua1` rather than `MAIN-modbus` because only that driver owns native conditions; it is the same handler.) So both quality paths this issue reported as unreachable are now reached. The one clause not asserted on the wire is condition `Quality` itself — Client.CLI has no select clause for it in its alarm event filter and its `read` throws on a Bad DataValue before printing. That is a CLI observability gap, not a gap in this fix; the fan-out is observed one layer in. Docs: `docs/DriverLifecycle.md` §"The comms-loss watchdog", `docs/AlarmTracking.md` (stale caveat replaced), and CLAUDE.md.
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#527
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?