fix(drivers): detect mid-run comms loss and recover from it (#527)
DriverInstanceActor.DisconnectObserved had no production sender. The only paths into Reconnecting were a failed *initial* connect and an operator's Force Reconnect, so a driver that connected and then lost its device stayed Connected indefinitely: publishing Bad for every tag, never re-initialising, and NOT recovering when the device returned. PublishHealthSnapshot read GetHealth() for reporting only and never acted on a driver reporting itself unhealthy. Both comms-loss quality paths -- #477's native-condition annotation and #481's scripted-alarm input fan-out -- hang off ConnectivityChanged, so both were correctly wired to a signal that never fired. The Connected health tick now evaluates a watchdog and self-sends DisconnectObserved when the driver reports a non-Healthy state AND its LastSuccessfulRead has been frozen for DefaultCommsLossTimeout (90s). The conjunction is the design, and the issue's own proposal -- "non-Healthy for N consecutive polls" -- is wrong. Degraded means *connected but some data is bad*; several drivers write health per tag inside the read loop (ModbusDriver.ReadAsync), so one unreadable address latches Degraded forever against a perfectly reachable device, and a state-only watchdog would reconnect that driver every 90s indefinitely -- worse than the bug. LastSuccessfulRead is the honest evidence: preserved across Degraded/Faulted writes, advanced by any success. The state check remains the second conjunct so an idle Healthy driver with nothing subscribed is not declared dead for not reading. Verified across all 12 drivers that a sustained failure does reach a non-Healthy state -- nine poll drivers via Degraded, MQTT via live connection state, Galaxy via its reconnect supervisor. CalculationDriver reports Healthy while running and so can never trip, which is correct: it has no transport. Also: 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 -- latent while only a manual Force Reconnect reached this path, but the watchdog makes it automatic and unbounded (~360 leaks for an hour-long outage at the 10s retry). Tests: 8 new in DriverInstanceActorCommsLossWatchdogTests, each absence assertion carrying a positive control (a proven count of processed health-poll ticks). Falsified five ways -- dropping either conjunct reds exactly the test written for it, and removing the teardown, the null baseline, or the watchdog call each reds its own guard. Live gate PASSED on docker-dev (Modbus + otopcua-pymodbus-standard), run twice: - fixture stopped -> watchdog fires at ~108s, "declaring comms lost" - fan-out observed at Debug: "pushed BadNoCommunication for 2 mux ref(s)" (#481 Layer 4) and the #477 native-condition annotation on a driver owning conditions - fixture restarted -> reconnected in ~8s with NO node restart; both the raw (ns=2) and UNS (ns=3) NodeIds read Good with fresh timestamps Claude-Session: https://claude.ai/code/session_015p7wGqy3YpZNCpDzTpGMKo
This commit is contained in:
Joseph Doherty
@@ -141,6 +141,23 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
/// <summary>Interval between periodic health-poll heartbeats sent to the snapshot store.</summary>
|
||||
public static readonly TimeSpan HealthPollInterval = TimeSpan.FromSeconds(30);
|
||||
|
||||
/// <summary>
|
||||
/// How long a Connected driver may go without a single successful read — while also reporting
|
||||
/// itself non-Healthy — before the actor declares comms lost (Gitea #527). Evaluated on the
|
||||
/// existing <see cref="HealthPollInterval"/> tick, so the effective detection granularity is
|
||||
/// 30 s and the worst-case detection latency is this value plus one tick.
|
||||
/// </summary>
|
||||
/// <remarks>
|
||||
/// 90 s = three health-poll ticks. Long enough that a device answering slowly under load is not
|
||||
/// torn down, short enough that an operator watching a dead PLC sees it inside two minutes.
|
||||
/// Hardcoded rather than exposed in appsettings, matching <see cref="HealthPollInterval"/> and
|
||||
/// <see cref="DefaultReconnectInterval"/>. Unlike the periodic drift-detector removed by Gitea
|
||||
/// #523, this generates <b>no</b> outbound traffic on a healthy system: the watchdog is a local
|
||||
/// read of <see cref="IDriver.GetHealth"/>, and it only reaches the network once a driver has
|
||||
/// already stopped reading successfully.
|
||||
/// </remarks>
|
||||
public static readonly TimeSpan DefaultCommsLossTimeout = TimeSpan.FromSeconds(90);
|
||||
|
||||
private readonly IDriver _driver;
|
||||
|
||||
/// <summary>Phase 6.1 resilience seam: every guarded driver-capability call this actor makes is
|
||||
@@ -158,6 +175,14 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
|
||||
private readonly TimeSpan _healthPollInterval;
|
||||
|
||||
/// <summary>Comms-loss watchdog threshold (#527); <see cref="TimeSpan.Zero"/> or negative disables it.</summary>
|
||||
private readonly TimeSpan _commsLossTimeout;
|
||||
|
||||
/// <summary>When the actor last entered <c>Connected</c>. The comms-loss watchdog's baseline for a
|
||||
/// driver that has never reported a successful read, so "connected but never read anything" is
|
||||
/// measurable rather than indefinitely undefined.</summary>
|
||||
private DateTime _connectedSinceUtc;
|
||||
|
||||
private readonly ILoggingAdapter _log = Context.GetLogger();
|
||||
private string? _currentConfigJson;
|
||||
|
||||
@@ -229,6 +254,9 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
/// <param name="healthPollInterval">Optional period of the health-poll heartbeat, which also drives the
|
||||
/// subscription reconcile (<see cref="ReconcileSubscription"/>); defaults to
|
||||
/// <see cref="HealthPollInterval"/>. Exists so a test can drive the reconcile without waiting 30 s.</param>
|
||||
/// <param name="commsLossTimeout">Optional comms-loss watchdog threshold (#527); defaults to
|
||||
/// <see cref="DefaultCommsLossTimeout"/>. <see cref="TimeSpan.Zero"/> disables the watchdog — used by
|
||||
/// tests that need a Connected driver to stay Connected while reporting non-Healthy.</param>
|
||||
/// <returns>A <see cref="Akka.Actor.Props"/> instance configured to create the wrapped <see cref="DriverInstanceActor"/>.</returns>
|
||||
public static Props Props(
|
||||
IDriver driver,
|
||||
@@ -237,7 +265,8 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
IDriverHealthPublisher? healthPublisher = null,
|
||||
string? clusterId = null,
|
||||
IDriverCapabilityInvoker? invoker = null,
|
||||
TimeSpan? healthPollInterval = null) =>
|
||||
TimeSpan? healthPollInterval = null,
|
||||
TimeSpan? commsLossTimeout = null) =>
|
||||
Akka.Actor.Props.Create(() => new DriverInstanceActor(
|
||||
driver,
|
||||
reconnectInterval ?? DefaultReconnectInterval,
|
||||
@@ -245,7 +274,8 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
healthPublisher ?? NullDriverHealthPublisher.Instance,
|
||||
clusterId ?? string.Empty,
|
||||
invoker,
|
||||
healthPollInterval));
|
||||
healthPollInterval,
|
||||
commsLossTimeout));
|
||||
|
||||
/// <summary>
|
||||
/// Returns true when the driver should boot in DEV-STUB mode based on host platform and
|
||||
@@ -278,6 +308,8 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
/// defaults to <see cref="NullDriverCapabilityInvoker"/> (pass-through) when null.</param>
|
||||
/// <param name="healthPollInterval">Period of the health-poll heartbeat, which also drives the
|
||||
/// subscription reconcile; defaults to <see cref="HealthPollInterval"/> when null.</param>
|
||||
/// <param name="commsLossTimeout">Comms-loss watchdog threshold (#527); defaults to
|
||||
/// <see cref="DefaultCommsLossTimeout"/> when null, and is disabled when zero or negative.</param>
|
||||
public DriverInstanceActor(
|
||||
IDriver driver,
|
||||
TimeSpan reconnectInterval,
|
||||
@@ -285,7 +317,8 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
IDriverHealthPublisher? healthPublisher = null,
|
||||
string? clusterId = null,
|
||||
IDriverCapabilityInvoker? invoker = null,
|
||||
TimeSpan? healthPollInterval = null)
|
||||
TimeSpan? healthPollInterval = null,
|
||||
TimeSpan? commsLossTimeout = null)
|
||||
{
|
||||
_driver = driver;
|
||||
_invoker = invoker ?? NullDriverCapabilityInvoker.Instance;
|
||||
@@ -294,6 +327,7 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
_healthPublisher = healthPublisher ?? NullDriverHealthPublisher.Instance;
|
||||
_reconnectInterval = reconnectInterval;
|
||||
_healthPollInterval = healthPollInterval ?? HealthPollInterval;
|
||||
_commsLossTimeout = commsLossTimeout ?? DefaultCommsLossTimeout;
|
||||
OtOpcUaTelemetry.DriverInstanceLifecycle.Add(1,
|
||||
new KeyValuePair<string, object?>("event", startStubbed ? "spawn_stub" : "spawn"),
|
||||
new KeyValuePair<string, object?>("driver_type", driver.DriverType));
|
||||
@@ -403,6 +437,10 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
// non-Good "waiting for initial data" quality at materialise, and this is what confirms them Good.
|
||||
Context.Parent.Tell(new ConnectivityChanged(_driverInstanceId, Connected: true));
|
||||
|
||||
// #527 — baseline for the comms-loss watchdog. Re-stamped on every Connected entry so a driver that
|
||||
// reconnects but never manages a read is measured from THIS connect, not from a stale earlier one.
|
||||
_connectedSinceUtc = DateTime.UtcNow;
|
||||
|
||||
ReceiveAsync<ApplyDelta>(HandleApplyDeltaAsync);
|
||||
Receive<DisconnectObserved>(msg =>
|
||||
{
|
||||
@@ -456,11 +494,76 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
Receive<HostStatusRaised>(_ => PublishHealthSnapshot());
|
||||
Receive<HealthPollTick>(_ =>
|
||||
{
|
||||
PublishHealthSnapshot();
|
||||
// One GetHealth observation feeds both the snapshot publish and the watchdog — reading it
|
||||
// twice would let the two disagree about the same tick.
|
||||
var health = PublishHealthSnapshot();
|
||||
EvaluateCommsLossWatchdog(health);
|
||||
ReconcileSubscription();
|
||||
});
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Gitea #527 — the comms-loss watchdog. Declares a Connected driver disconnected once it has gone
|
||||
/// <see cref="_commsLossTimeout"/> without a single successful read <b>while also</b> reporting
|
||||
/// itself non-Healthy, by self-sending <see cref="DisconnectObserved"/>.
|
||||
/// </summary>
|
||||
/// <remarks>
|
||||
/// <para>
|
||||
/// <b>Why this exists.</b> <see cref="DisconnectObserved"/> had no production sender at all. The only
|
||||
/// ways into <c>Reconnecting</c> were a failed <em>initial</em> connect and an operator's Force
|
||||
/// Reconnect, so a driver that connected successfully and then lost its device stayed Connected
|
||||
/// forever: it published Bad for every tag, never re-initialised, and did not recover when the device
|
||||
/// came back — live-confirmed against a stopped Modbus fixture, which needed a node restart. Both
|
||||
/// comms-loss quality paths (#477 native conditions, #481 scripted-alarm inputs) hang off
|
||||
/// <see cref="ConnectivityChanged"/>, so both were wired to a signal that never fired.
|
||||
/// <c>OpcUaClientDriver</c>'s own reconnect-exhausted branch already assumed this mechanism existed
|
||||
/// ("the Core never learns it must offer an operator reinitialize") — it did not.
|
||||
/// </para>
|
||||
/// <para>
|
||||
/// <b>Why the trip condition is a conjunction, and NOT simply "non-Healthy for N polls".</b>
|
||||
/// <see cref="DriverState.Degraded"/> means <em>connected but some data is bad</em> — the enum says
|
||||
/// so. Several drivers publish health per-tag inside their read loop (<c>ModbusDriver.ReadAsync</c>
|
||||
/// writes Healthy or Degraded once per reference), so a single unreadable address leaves the driver
|
||||
/// Degraded whenever it happens to be the last tag read, indefinitely, against a perfectly healthy
|
||||
/// device. Tripping on state alone would tear that driver down every watchdog period forever —
|
||||
/// strictly worse than the bug being fixed.
|
||||
/// </para>
|
||||
/// <para>
|
||||
/// <see cref="DriverHealth.LastSuccessfulRead"/> is the honest liveness evidence: every driver
|
||||
/// advances it on any successful read and <em>preserves</em> it across Degraded/Faulted writes. One
|
||||
/// bad tag among good ones keeps it moving; a device that is genuinely gone freezes it. The state
|
||||
/// check is still required as the second conjunct, because a Healthy driver with nothing subscribed
|
||||
/// legitimately never reads at all and must not be declared dead for being idle.
|
||||
/// </para>
|
||||
/// <para>
|
||||
/// <b>Drivers this cannot fire for, by construction.</b> <c>CalculationDriver</c> reports Healthy
|
||||
/// whenever it is running (it has no transport to be degraded about), so it never trips — correct,
|
||||
/// since there is nothing to reconnect to. Every other driver in the tree reaches a non-Healthy
|
||||
/// state on sustained failure: the nine poll drivers via Degraded, MQTT via its live connection
|
||||
/// state, Galaxy via its reconnect supervisor.
|
||||
/// </para>
|
||||
/// </remarks>
|
||||
/// <param name="health">The health observed on this tick, or null when <see cref="IDriver.GetHealth"/>
|
||||
/// threw — a failed observation is not evidence of comms loss, so it never advances the watchdog.</param>
|
||||
private void EvaluateCommsLossWatchdog(DriverHealth? health)
|
||||
{
|
||||
if (_commsLossTimeout <= TimeSpan.Zero) return;
|
||||
if (health is not { } observed) return;
|
||||
if (observed.State == DriverState.Healthy) return;
|
||||
|
||||
// A driver that has never reported a successful read is measured from the current Connected entry.
|
||||
var lastEvidence = observed.LastSuccessfulRead ?? _connectedSinceUtc;
|
||||
var silence = DateTime.UtcNow - lastEvidence;
|
||||
if (silence < _commsLossTimeout) return;
|
||||
|
||||
_log.Warning(
|
||||
"DriverInstance {Id}: no successful read for {Silence} while reporting {State} ({Error}) — " +
|
||||
"declaring comms lost and reconnecting",
|
||||
_driverInstanceId, silence, observed.State, observed.LastError ?? "no error reported");
|
||||
Self.Tell(new DisconnectObserved(
|
||||
$"no successful read for {silence.TotalSeconds:F0}s while reporting {observed.State}"));
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Periodic desired-vs-actual subscription reconcile (#488), riding the existing <c>health-poll</c>
|
||||
/// tick. While Connected, a driver that has a desired subscription set but no live handle is
|
||||
@@ -514,7 +617,8 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
// (a comms-lost driver emits no alarm events, so this is the ONLY signal that the source is unreachable).
|
||||
Context.Parent.Tell(new ConnectivityChanged(_driverInstanceId, Connected: false));
|
||||
|
||||
Receive<RetryConnect>(_ => InitializeAsync(_currentConfigJson ?? "{}"));
|
||||
// #527 — tear the dead transport down before re-initialising, or every retry leaks one.
|
||||
Receive<RetryConnect>(_ => InitializeAsync(_currentConfigJson ?? "{}", teardownFirst: true));
|
||||
// Fast-fail writes while reconnecting (same reason as Connecting — avoids the 8s host Ask
|
||||
// timeout on an inbound write to a transiently-down driver). Synchronous Receive.
|
||||
Receive<WriteAttribute>(_ =>
|
||||
@@ -562,16 +666,45 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
Timers.StartPeriodicTimer("retry-connect", RetryConnect.Instance, _reconnectInterval);
|
||||
}
|
||||
|
||||
private void InitializeAsync(string driverConfigJson)
|
||||
/// <param name="driverConfigJson">The config blob to initialise the driver with.</param>
|
||||
/// <param name="teardownFirst">
|
||||
/// When true, <see cref="IDriver.ShutdownAsync"/> is awaited before <see cref="IDriver.InitializeAsync"/>
|
||||
/// — the sequence every driver's own <c>ReinitializeAsync</c> uses. Set on the <c>Reconnecting</c>
|
||||
/// retry path (#527), because several drivers <em>overwrite</em> their transport field in
|
||||
/// <c>InitializeAsync</c> without disposing the previous one: <c>ModbusDriver</c> assigns
|
||||
/// <c>_transport = _transportFactory(...)</c> and <c>MqttDriver</c> assigns <c>_connection</c>, both
|
||||
/// over an <see cref="IAsyncDisposable"/>. Re-initialising without tearing down therefore leaks one
|
||||
/// socket (and, for Modbus, a poll engine) per attempt. That was latent while nothing but an
|
||||
/// operator's Force Reconnect ever re-entered this path; the watchdog makes it automatic and
|
||||
/// unbounded — a device down for an hour would leak ~360 transports at the 10 s retry interval.
|
||||
/// Best-effort and never fatal: a driver that throws on shutdown still gets its initialise attempt.
|
||||
/// </param>
|
||||
private void InitializeAsync(string driverConfigJson, bool teardownFirst = false)
|
||||
{
|
||||
_currentConfigJson = driverConfigJson;
|
||||
var generation = ++_initGeneration;
|
||||
var self = Self;
|
||||
var log = _log;
|
||||
var driverInstanceId = _driverInstanceId;
|
||||
var driver = _driver;
|
||||
_ = Task.Run(async () =>
|
||||
{
|
||||
try
|
||||
{
|
||||
await _driver.InitializeAsync(driverConfigJson, CancellationToken.None);
|
||||
if (teardownFirst)
|
||||
{
|
||||
try
|
||||
{
|
||||
await driver.ShutdownAsync(CancellationToken.None);
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
log.Warning(ex,
|
||||
"DriverInstance {Id}: ShutdownAsync threw before a reconnect attempt; " +
|
||||
"initialising anyway", driverInstanceId);
|
||||
}
|
||||
}
|
||||
await driver.InitializeAsync(driverConfigJson, CancellationToken.None);
|
||||
self.Tell(new InitializeSucceeded(generation));
|
||||
}
|
||||
catch (Exception ex)
|
||||
@@ -1006,11 +1139,16 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
/// every 30s when nothing has changed. Newly-joined SignalR clients still get the current
|
||||
/// snapshot via <c>DriverStatusHub.JoinDriver</c> which reads the store directly.
|
||||
/// </summary>
|
||||
private void PublishHealthSnapshot()
|
||||
/// <returns>The health observed on this call, or null when <see cref="IDriver.GetHealth"/> threw.
|
||||
/// Returned so the caller can reuse the same observation — the #527 comms-loss watchdog rides this
|
||||
/// call rather than polling the driver a second time and risking a different answer.</returns>
|
||||
private DriverHealth? PublishHealthSnapshot()
|
||||
{
|
||||
DriverHealth? observed = null;
|
||||
try
|
||||
{
|
||||
var health = _driver.GetHealth();
|
||||
observed = health;
|
||||
var errorCount = ErrorCount5Min();
|
||||
var hostStatuses = CurrentHostStatuses();
|
||||
// _rediscoveryNeededUtc is PART OF THE FINGERPRINT on purpose. A rediscovery raise on an
|
||||
@@ -1027,7 +1165,7 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
var fingerprint = (health.State, health.LastSuccessfulRead, health.LastError, errorCount,
|
||||
_rediscoveryNeededUtc, HostStatusDigest(hostStatuses));
|
||||
if (_lastPublishedFingerprint is { } prev && prev.Equals(fingerprint))
|
||||
return;
|
||||
return observed;
|
||||
_lastPublishedFingerprint = fingerprint;
|
||||
_healthPublisher.Publish(
|
||||
_clusterId, _driverInstanceId, health, errorCount, _rediscoveryNeededUtc, _rediscoveryReason,
|
||||
@@ -1037,6 +1175,7 @@ public sealed class DriverInstanceActor : ReceiveActor, IWithTimers
|
||||
{
|
||||
_log.Warning(ex, "DriverInstance {Id}: GetHealth threw during health publish; skipping", _driverInstanceId);
|
||||
}
|
||||
return observed;
|
||||
}
|
||||
|
||||
/// <summary>Order-insensitive value digest of a host-status list for the publish fingerprint. Null in,
|
||||
|
||||
Reference in New Issue
Block a user