Files
lmxopcua/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Drivers/DriverInstanceActorCommsLossWatchdogTests.cs
T
Joseph Doherty 5a7a08deca 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
2026-07-31 10:58:38 -04:00

331 lines
16 KiB
C#

using Akka.Actor;
using Shouldly;
using Xunit;
using ZB.MOM.WW.OtOpcUa.Core.Abstractions;
using ZB.MOM.WW.OtOpcUa.Runtime.Drivers;
using ZB.MOM.WW.OtOpcUa.Runtime.Tests.Harness;
namespace ZB.MOM.WW.OtOpcUa.Runtime.Tests.Drivers;
/// <summary>
/// Gitea #527 — the comms-loss watchdog that gives <see cref="DriverInstanceActor.DisconnectObserved"/>
/// its first production sender.
/// </summary>
/// <remarks>
/// <para>
/// <b>The defect.</b> Nothing in <c>src/</c> ever sent <c>DisconnectObserved</c>. A driver that
/// connected and then lost its device stayed <c>Connected</c> indefinitely — publishing Bad for
/// every tag, never re-initialising, and not recovering when the device returned. Live-confirmed
/// against a stopped Modbus fixture, which needed a node restart.
/// </para>
/// <para>
/// <b>What these tests are really pinning is the trip CONDITION, not the plumbing.</b> The obvious
/// design — "non-Healthy for N consecutive polls" — is wrong, and
/// <see cref="A_degraded_driver_that_is_still_reading_successfully_is_left_alone"/> is the test that
/// says so. <see cref="DriverState.Degraded"/> means <i>connected but some data is bad</i>, and
/// several drivers write health per-tag inside their read loop, so one unreadable address can leave
/// a perfectly healthy device's driver Degraded forever. Tripping on state alone would reconnect
/// that driver every 90 s in production — worse than the bug being fixed. The conjunction with a
/// frozen <see cref="DriverHealth.LastSuccessfulRead"/> is what makes the signal honest, and
/// <see cref="An_idle_healthy_driver_with_a_stale_last_read_is_left_alone"/> pins the other half.
/// </para>
/// <para>
/// Every absence assertion carries a positive control — a proven number of health-poll ticks
/// actually processed (<see cref="HealthControlledStubDriver.HealthReadCount"/>) — so "the watchdog
/// did not fire" can never pass merely because nothing ran.
/// </para>
/// </remarks>
public sealed class DriverInstanceActorCommsLossWatchdogTests : RuntimeActorTestBase
{
private static readonly TimeSpan FastPoll = TimeSpan.FromMilliseconds(50);
private static readonly TimeSpan FastTimeout = TimeSpan.FromMilliseconds(250);
/// <summary>Drives the actor to Connected and returns once the connect has been announced.</summary>
private (IActorRef Actor, Akka.TestKit.TestProbe Parent) ConnectDriver(
HealthControlledStubDriver driver,
TimeSpan? commsLossTimeout = null,
TimeSpan? reconnectInterval = null)
{
var parent = CreateTestProbe();
var actor = parent.ChildActorOf(DriverInstanceActor.Props(
driver,
reconnectInterval: reconnectInterval ?? TimeSpan.FromSeconds(30),
healthPollInterval: FastPoll,
commsLossTimeout: commsLossTimeout ?? FastTimeout));
actor.Tell(new DriverInstanceActor.InitializeRequested("{}"));
// Connected entry announces Connected=true; consuming it here leaves the probe holding only
// whatever the watchdog does (or does not) send next.
parent.ExpectMsg<DriverInstanceActor.ConnectivityChanged>(TimeSpan.FromSeconds(3))
.Connected.ShouldBeTrue();
return (actor, parent);
}
/// <summary>
/// The core of #527: a Connected driver whose device has gone away — non-Healthy, and no successful
/// read since well before the threshold — is declared disconnected and announces comms loss to the
/// host, which is the signal #477 and #481 both hang off.
/// </summary>
[Fact]
public void A_connected_driver_that_stops_reading_successfully_is_declared_disconnected()
{
var driver = new HealthControlledStubDriver
{
// The live shape: reads fail, the driver reports Degraded, and LastSuccessfulRead is frozen
// at the instant the device died.
Health = new DriverHealth(DriverState.Degraded, DateTime.UtcNow.AddMinutes(-5), "socket timeout"),
};
var (_, parent) = ConnectDriver(driver);
parent.ExpectMsg<DriverInstanceActor.ConnectivityChanged>(TimeSpan.FromSeconds(3))
.Connected.ShouldBeFalse();
}
/// <summary>
/// The falsifying control for the trip condition, and the reason it is not "non-Healthy for N polls".
/// This driver is <b>permanently Degraded</b> — modelling one unreadable address among many, which
/// <c>ModbusDriver.ReadAsync</c> leaves latched whenever the bad tag is read last — but it is still
/// reading successfully, so <c>LastSuccessfulRead</c> keeps advancing. It must be left alone.
/// A state-only watchdog would tear this driver down on every threshold, forever.
/// </summary>
[Fact]
public void A_degraded_driver_that_is_still_reading_successfully_is_left_alone()
{
var driver = new HealthControlledStubDriver
{
// Recomputed per call: Degraded, but LastSuccessfulRead is always fresh.
HealthFactory = () => new DriverHealth(DriverState.Degraded, DateTime.UtcNow, "one bad tag"),
};
var (_, parent) = ConnectDriver(driver);
// Positive control: prove the watchdog genuinely ran, many times, over a span far longer than the
// trip threshold. Without this the absence assertion below would pass against a watchdog that
// never executed at all.
AwaitCondition(
() => driver.HealthReadCount >= 12,
TimeSpan.FromSeconds(5),
"health-poll ticks did not run — the absence assertion below would be vacuous");
driver.ObservedSpan.ShouldBeGreaterThan(FastTimeout, "the observation window never exceeded the trip threshold");
parent.ExpectNoMsg(TimeSpan.FromMilliseconds(200));
}
/// <summary>
/// The other conjunct. A Healthy driver with nothing subscribed legitimately never reads, so its
/// <c>LastSuccessfulRead</c> is arbitrarily stale. Staleness alone must not declare it dead.
/// </summary>
[Fact]
public void An_idle_healthy_driver_with_a_stale_last_read_is_left_alone()
{
var driver = new HealthControlledStubDriver
{
Health = new DriverHealth(DriverState.Healthy, DateTime.UtcNow.AddHours(-2), null),
};
var (_, parent) = ConnectDriver(driver);
AwaitCondition(
() => driver.HealthReadCount >= 12,
TimeSpan.FromSeconds(5),
"health-poll ticks did not run — the absence assertion below would be vacuous");
parent.ExpectNoMsg(TimeSpan.FromMilliseconds(200));
}
/// <summary>
/// A driver that connects but never manages a single read reports <c>LastSuccessfulRead = null</c>,
/// so staleness has no natural baseline. The watchdog measures from the Connected entry instead —
/// otherwise a never-read driver would be the one case that could never be declared dead.
/// </summary>
[Fact]
public void A_driver_that_never_reads_after_connecting_is_declared_disconnected()
{
var driver = new HealthControlledStubDriver
{
Health = new DriverHealth(DriverState.Degraded, LastSuccessfulRead: null, "never read"),
};
var (_, parent) = ConnectDriver(driver);
parent.ExpectMsg<DriverInstanceActor.ConnectivityChanged>(TimeSpan.FromSeconds(3))
.Connected.ShouldBeFalse();
}
/// <summary>
/// A <see cref="IDriver.GetHealth"/> that throws is a failed observation, not evidence that the
/// device is gone. Treating it as a trip would let a buggy health accessor cycle a working driver.
/// </summary>
[Fact]
public void A_throwing_GetHealth_is_not_evidence_of_comms_loss()
{
var driver = new HealthControlledStubDriver { GetHealthShouldThrow = true };
var (_, parent) = ConnectDriver(driver);
AwaitCondition(
() => driver.HealthReadCount >= 12,
TimeSpan.FromSeconds(5),
"health-poll ticks did not run — the absence assertion below would be vacuous");
parent.ExpectNoMsg(TimeSpan.FromMilliseconds(200));
}
/// <summary>
/// #527's second acceptance criterion, end to end: the driver recovers by itself once the device
/// returns, with no node restart. Trip → Reconnecting → retry re-initialises → Connected, and the
/// host is told connectivity is back.
/// </summary>
[Fact]
public void The_driver_recovers_on_its_own_once_the_device_returns()
{
var driver = new HealthControlledStubDriver
{
Health = new DriverHealth(DriverState.Degraded, DateTime.UtcNow.AddMinutes(-5), "socket timeout"),
};
var (_, parent) = ConnectDriver(driver, reconnectInterval: TimeSpan.FromMilliseconds(100));
parent.ExpectMsg<DriverInstanceActor.ConnectivityChanged>(TimeSpan.FromSeconds(3))
.Connected.ShouldBeFalse();
// The device comes back: the next initialise attempt succeeds and reads resume.
driver.Health = new DriverHealth(DriverState.Healthy, DateTime.UtcNow, null);
parent.ExpectMsg<DriverInstanceActor.ConnectivityChanged>(TimeSpan.FromSeconds(5))
.Connected.ShouldBeTrue();
driver.InitializeCount.ShouldBeGreaterThan(1, "the driver was never re-initialised");
}
/// <summary>
/// The leak guard. Several drivers overwrite an <see cref="IAsyncDisposable"/> transport field
/// inside <c>InitializeAsync</c> without disposing the previous one (<c>ModbusDriver._transport</c>,
/// <c>MqttDriver._connection</c>), so re-initialising without a teardown leaks one socket per
/// attempt. Latent while only an operator's Force Reconnect re-entered this path; the watchdog
/// makes it automatic and unbounded, so the retry must shut down first.
/// </summary>
[Fact]
public void A_reconnect_attempt_tears_the_dead_transport_down_before_re_initialising()
{
var driver = new HealthControlledStubDriver
{
Health = new DriverHealth(DriverState.Degraded, DateTime.UtcNow.AddMinutes(-5), "socket timeout"),
};
var (_, parent) = ConnectDriver(driver, reconnectInterval: TimeSpan.FromMilliseconds(100));
parent.ExpectMsg<DriverInstanceActor.ConnectivityChanged>(TimeSpan.FromSeconds(3))
.Connected.ShouldBeFalse();
AwaitCondition(
() => driver.InitializeCount >= 2,
TimeSpan.FromSeconds(5),
"the reconnect retry never re-initialised the driver");
// Ordering, not just counts: EVERY re-initialise must be immediately preceded by a shutdown, since
// it is the initialise that overwrites the transport field. Asserting ShutdownCount > 0 alone would
// also pass on a teardown that happened afterwards, which frees nothing before the overwrite.
//
// The sequence is deliberately not pinned to a fixed length: this driver reports stale health even
// after a successful re-init, so the watchdog trips again and the cycle repeats — the real
// behaviour for a device that accepts a connection but serves no data. Every additional cycle is
// another chance for the invariant to be violated, so a longer run is a stronger test, not a
// flakier one.
var lifecycle = driver.Lifecycle;
lifecycle[0].ShouldBe("init", "the first connect must not tear down a driver that was never up");
for (var i = 1; i < lifecycle.Count; i++)
{
if (lifecycle[i] != "init") continue;
lifecycle[i - 1].ShouldBe(
"shutdown",
$"re-initialise at index {i} was not preceded by a teardown — the previous transport leaks. " +
$"Full sequence: [{string.Join(", ", lifecycle)}]");
}
}
/// <summary>
/// The escape hatch is real: a zero threshold disables the watchdog entirely, leaving the
/// pre-#527 behaviour. Pinned because tests elsewhere rely on a Connected driver staying Connected
/// while reporting non-Healthy.
/// </summary>
[Fact]
public void A_zero_threshold_disables_the_watchdog()
{
var driver = new HealthControlledStubDriver
{
Health = new DriverHealth(DriverState.Degraded, DateTime.UtcNow.AddMinutes(-5), "socket timeout"),
};
var (_, parent) = ConnectDriver(driver, commsLossTimeout: TimeSpan.Zero);
AwaitCondition(
() => driver.HealthReadCount >= 12,
TimeSpan.FromSeconds(5),
"health-poll ticks did not run — the absence assertion below would be vacuous");
parent.ExpectNoMsg(TimeSpan.FromMilliseconds(200));
}
}
/// <summary>
/// A <see cref="StubDriver"/> whose health is fully driven by the test, counting observations so an
/// absence assertion can prove the watchdog actually ran, and recording lifecycle call ORDER so the
/// teardown-before-reinitialise guard can assert sequence rather than mere counts.
/// </summary>
internal sealed class HealthControlledStubDriver : StubDriver
{
private readonly Lock _gate = new();
private int _healthReadCount;
private DateTime _firstReadUtc;
private DateTime _lastReadUtc;
/// <summary>The health returned by every <see cref="GetHealth"/> call; ignored when
/// <see cref="HealthFactory"/> is set.</summary>
public DriverHealth Health { get; set; } = new(DriverState.Healthy, DateTime.UtcNow, null);
/// <summary>Per-call health, for modelling a driver whose <c>LastSuccessfulRead</c> keeps advancing.</summary>
public Func<DriverHealth>? HealthFactory { get; set; }
/// <summary>When true, <see cref="GetHealth"/> throws — a failed observation.</summary>
public bool GetHealthShouldThrow { get; set; }
/// <summary>Number of <see cref="GetHealth"/> calls; the positive control for absence assertions.</summary>
public int HealthReadCount => Volatile.Read(ref _healthReadCount);
/// <summary>Wall-clock span between the first and last observation — proves an absence window
/// genuinely exceeded the trip threshold rather than merely counting fast ticks.</summary>
public TimeSpan ObservedSpan
{
get { lock (_gate) return _lastReadUtc - _firstReadUtc; }
}
/// <summary>Ordered lifecycle log: <c>"init"</c> / <c>"shutdown"</c>, in call order.</summary>
public IReadOnlyList<string> Lifecycle
{
get { lock (_gate) return _lifecycle.ToArray(); }
}
private readonly List<string> _lifecycle = new();
/// <inheritdoc />
public override async Task InitializeAsync(string driverConfigJson, CancellationToken cancellationToken)
{
lock (_gate) _lifecycle.Add("init");
await base.InitializeAsync(driverConfigJson, cancellationToken);
}
/// <inheritdoc />
public override Task ShutdownAsync(CancellationToken cancellationToken)
{
lock (_gate) _lifecycle.Add("shutdown");
return base.ShutdownAsync(cancellationToken);
}
/// <inheritdoc />
public override DriverHealth GetHealth()
{
Interlocked.Increment(ref _healthReadCount);
lock (_gate)
{
var now = DateTime.UtcNow;
if (_firstReadUtc == default) _firstReadUtc = now;
_lastReadUtc = now;
}
if (GetHealthShouldThrow) throw new InvalidOperationException("stub-health-fail");
return HealthFactory is { } factory ? factory() : Health;
}
}