beb1c583b1
Live gate A1 (docker-dev, opc-plc restart / SIGINT / kill): the fast path never fired — a real process stop delivers no session status; the keep-alives report BadSecureChannelClosed (0x80860000) once, then BadConnectionClosed (0x80AE0000) interleaved with BadNoCommunication for the whole outage. Reproduced in-process with TcpStallProxy.HardClose (reset every connection, refuse new ones; server and session alive behind it): the identical sequence, and the SDK 1.5.378 session never opens a new connection on its own (48 s with the proxy accepting again, zero attempts) — a closed channel cannot recover in place. The driver now treats BadSecureChannelClosed/BadConnectionClosed as definitive on the SECOND closed-channel keep-alive failure in one outage (a good keep-alive resets the count), raising ConnectionLost ~1 keep-alive after the drop. BadNoCommunication / BadRequestTimeout / BadNotConnected (stall/pause) stay with the watchdog; the stall test still sees no ConnectionLost. New wire test (hard close + reopen ⇒ raised once, SDK never reconnects, reinit brings the identical value back Good) and unit tests (sustained raises once; a single blip that recovers does not) — all red on the previous code. Docs updated.
232 lines
15 KiB
C#
232 lines
15 KiB
C#
using Opc.Ua;
|
|
using Shouldly;
|
|
using Xunit;
|
|
using ZB.MOM.WW.OtOpcUa.Core.Abstractions;
|
|
|
|
namespace ZB.MOM.WW.OtOpcUa.OpcUaServer.IntegrationTests;
|
|
|
|
/// <summary>
|
|
/// Gitea #676 item 1 — the IN-PLACE blip (#670): the upstream stops answering but the TCP connection and the
|
|
/// session survive, keep-alives fail, then traffic resumes before the session times out. Until now only the live
|
|
/// gate (<c>docker pause</c> of opc-plc) covered it. <see cref="TcpStallProxy"/> reproduces it on loopback: the driver
|
|
/// connects THROUGH the proxy (which works only because of the #676 endpoint rewrite — the server advertises its own
|
|
/// port, which would bypass the proxy), and pausing the proxy stalls every byte without closing anything.
|
|
/// </summary>
|
|
/// <remarks>
|
|
/// Writing this test found a real defect: a change the server published right after the stall ended rode a Publish
|
|
/// response that had been in flight across the stall; the SDK timed that request out, dropped the response and never
|
|
/// republished it, so the node stayed Good on the PRE-change value indefinitely. The driver's trailing reconcile read
|
|
/// (<c>ReconcileAfterRecoveryAsync</c>) is the fix; the "40.0 arrives" leg below goes red without it.
|
|
/// </remarks>
|
|
[Trait("Category", "Integration")]
|
|
public sealed class OpcUaClientDriverStallWireTests
|
|
{
|
|
private const uint BadNoCommunication = 0x80310000u;
|
|
|
|
private static async Task WaitAsync(Func<bool> condition, string because, TimeSpan? timeout = null)
|
|
{
|
|
var deadline = DateTime.UtcNow + (timeout ?? TimeSpan.FromSeconds(30));
|
|
while (DateTime.UtcNow < deadline)
|
|
{
|
|
if (condition()) return;
|
|
await Task.Delay(25);
|
|
}
|
|
condition().ShouldBeTrue(because);
|
|
}
|
|
|
|
private sealed record Seen(uint Status, object? Value, DateTime? Source);
|
|
|
|
[Fact]
|
|
public async Task A_stalled_connection_goes_Bad_once_and_recovers_in_place_on_the_same_session_without_regressing()
|
|
{
|
|
var ct = TestContext.Current.CancellationToken;
|
|
await using var rig = await OpcUaClientDriverWireTests.StartRigAsync("drv-stall", ct);
|
|
await using var proxy = TcpStallProxy.Start(new Uri(rig.EndpointUrl).Port);
|
|
OpcUaClientDriverWireTests.Publish(rig, OpcUaClientDriverWireTests.SpeedId, 10.0f);
|
|
|
|
// A 3 s operation timeout keeps the stall short (a keep-alive is declared failed when its request times out); a
|
|
// 120 s session timeout and a 3000-cycle (300 s at 100 ms) subscription lifetime keep both far outside the
|
|
// stall, so the test exercises the in-place recovery and nothing else.
|
|
await using var drv = OpcUaClientDriverWireTests.NewDriver(
|
|
rig, "wire-stall", endpointUrl: proxy.Through(rig.EndpointUrl), timeout: TimeSpan.FromSeconds(3),
|
|
sessionTimeout: TimeSpan.FromSeconds(120), subscriptionLifetimeCount: 3000);
|
|
var connectionLost = 0;
|
|
drv.ConnectionLost += (_, _) => Interlocked.Increment(ref connectionLost);
|
|
await drv.InitializeAsync("{}", ct);
|
|
proxy.AcceptedConnections.ShouldBeGreaterThan(0, "the session must run THROUGH the proxy, or pausing it proves nothing");
|
|
|
|
var seen = new List<Seen>();
|
|
drv.OnDataChange += (_, e) =>
|
|
{
|
|
if (e.FullReference == OpcUaClientDriverWireTests.SpeedRef)
|
|
lock (seen) seen.Add(new Seen(e.Snapshot.StatusCode, e.Snapshot.Value, e.Snapshot.SourceTimestampUtc));
|
|
};
|
|
await drv.SubscribeAsync([OpcUaClientDriverWireTests.SpeedRef], TimeSpan.FromMilliseconds(100), ct);
|
|
await WaitAsync(() => { lock (seen) return seen.Any(s => s is { Status: 0u, Value: 10.0f }); }, "initial value");
|
|
|
|
var session = drv.Session.ShouldNotBeNull();
|
|
var connectionsBefore = proxy.AcceptedConnections;
|
|
// Bad keep-alive TICKS: the SDK reports a failed tick as two events at the same instant (the request's status and
|
|
// BadNoCommunication), so events closer than half a keep-alive interval are one tick.
|
|
var badKeepAlives = 0;
|
|
var lastBadTick = DateTime.MinValue;
|
|
session.KeepAlive += (_, e) =>
|
|
{
|
|
if (!ServiceResult.IsBad(e.Status)) return;
|
|
lock (seen)
|
|
{
|
|
if (DateTime.UtcNow - lastBadTick < TimeSpan.FromMilliseconds(500)) return;
|
|
lastBadTick = DateTime.UtcNow;
|
|
badKeepAlives++;
|
|
}
|
|
};
|
|
// The SDK's late backlog flush: a data-carrying NotificationMessage whose sequence number is BELOW one already
|
|
// seen (keep-alive messages carry the next number). It is the positive control for the no-regression check.
|
|
uint maxSequence = 0;
|
|
var lateMessages = 0;
|
|
session.Notification += (_, e) =>
|
|
{
|
|
var msg = e.NotificationMessage;
|
|
if (msg is null) return;
|
|
lock (seen)
|
|
{
|
|
if (msg.SequenceNumber < maxSequence && msg.NotificationData.Count > 0) lateMessages++;
|
|
maxSequence = Math.Max(maxSequence, msg.SequenceNumber);
|
|
}
|
|
};
|
|
|
|
// ── Stall ────────────────────────────────────────────────────────────────────────────────────────────────
|
|
proxy.Pause();
|
|
await WaitAsync(() => { lock (seen) return seen.Any(s => s.Status == BadNoCommunication); },
|
|
"a stalled upstream must publish BadNoCommunication for the subscribed ref");
|
|
lock (seen) seen.Single(s => s.Status == BadNoCommunication).Value.ShouldBe(10.0f, "the Bad retains the value");
|
|
drv.GetHealth().State.ShouldNotBe(DriverState.Healthy);
|
|
var frozen = drv.GetHealth().LastSuccessfulRead.ShouldNotBeNull();
|
|
|
|
// The server's value moves on while the client cannot see it: away and back to the pre-outage value, so the
|
|
// recovered value is IDENTICAL to the one published Bad — the (value, status) dedup trap.
|
|
OpcUaClientDriverWireTests.Publish(rig, OpcUaClientDriverWireTests.SpeedId, 20.0f);
|
|
await Task.Delay(300, ct); // > one publishing interval, so the server queues 20.0 as its own notification
|
|
OpcUaClientDriverWireTests.Publish(rig, OpcUaClientDriverWireTests.SpeedId, 10.0f);
|
|
|
|
// Stays Bad and frozen across one further failed keep-alive tick (counted, not slept for).
|
|
int badAtDetection;
|
|
lock (seen) badAtDetection = badKeepAlives;
|
|
await WaitAsync(() => { lock (seen) return badKeepAlives > badAtDetection; }, "a further keep-alive must fail while stalled");
|
|
drv.GetHealth().LastSuccessfulRead.ShouldBe(frozen, "the read stamp is the #527 watchdog's silence measure");
|
|
lock (seen) seen.Count(s => s.Status == BadNoCommunication).ShouldBe(1, "one Bad per outage, not per keep-alive");
|
|
|
|
// ── Resume well inside the 30 s session timeout ──────────────────────────────────────────────────────────
|
|
proxy.Resume();
|
|
await WaitAsync(() => drv.GetHealth().State == DriverState.Healthy, "a resumed stall must recover in place");
|
|
int badIndex;
|
|
lock (seen) badIndex = seen.FindIndex(s => s.Status == BadNoCommunication);
|
|
await WaitAsync(() => { lock (seen) return seen.Skip(badIndex + 1).Any(s => s is { Status: 0u, Value: 10.0f }); },
|
|
"the identical value must be republished Good after the outage");
|
|
|
|
drv.Session.ShouldBeSameAs(session, "an in-place blip must not cost the session");
|
|
proxy.AcceptedConnections.ShouldBe(connectionsBefore, "and not the TCP connection either");
|
|
|
|
// A change published straight after recovery — while the Publish requests held across the stall are still
|
|
// being answered or timed out — must still reach the node.
|
|
OpcUaClientDriverWireTests.Publish(rig, OpcUaClientDriverWireTests.SpeedId, 40.0f);
|
|
await WaitAsync(() => { lock (seen) return seen.Any(s => s is { Status: 0u, Value: 40.0f }); },
|
|
"a change published right after recovery must reach the node (via the subscription or the trailing re-read)",
|
|
TimeSpan.FromSeconds(60));
|
|
await drv.ReconcileTaskForTest;
|
|
|
|
// The SDK flushes the notifications held during the stall seconds after recovery (the #670 F2 shape). Wait for
|
|
// that flush before judging ordering, or the check below would pass on a run where nothing late arrived.
|
|
await WaitAsync(() => { lock (seen) return lateMessages > 0; },
|
|
"the SDK's late backlog flush did not arrive — the no-regression check below would be vacuous",
|
|
TimeSpan.FromSeconds(60));
|
|
|
|
lock (seen)
|
|
{
|
|
var good = seen.Where(s => s.Status == 0u && s.Source is not null).ToList();
|
|
for (var i = 1; i < good.Count; i++)
|
|
good[i].Source!.Value.ShouldBeGreaterThanOrEqualTo(good[i - 1].Source!.Value,
|
|
$"published Good value #{i} ({good[i].Value}) regressed in source time — a late replay reached the " +
|
|
$"node. Sequence: [{string.Join(", ", good.Select(s => $"{s.Value}@{s.Source:HH:mm:ss.fff}"))}]");
|
|
seen.Last().Value.ShouldBe(40.0f, "nothing older may land after the latest value");
|
|
seen.Count(s => s.Status == BadNoCommunication).ShouldBe(1);
|
|
}
|
|
drv.GetHealth().State.ShouldBe(DriverState.Healthy);
|
|
drv.Session.ShouldBeSameAs(session);
|
|
Volatile.Read(ref connectionLost).ShouldBe(0,
|
|
"a stall is AMBIGUOUS (the session survived it) — it must go through the #527 watchdog, never the fast path");
|
|
}
|
|
|
|
/// <summary>
|
|
/// #676 live gate A1 — a real upstream process stop is a CLOSED connection, not a stall: the keep-alives report
|
|
/// <c>BadSecureChannelClosed</c>, then <c>BadConnectionClosed</c> (with <c>BadNoCommunication</c>) for the rest of
|
|
/// the outage, and the SDK never opens a new connection on its own — not even when the server (here, with the
|
|
/// session still alive behind the proxy) is reachable again. The driver must therefore raise
|
|
/// <c>ConnectionLost</c> once the closed channel is sustained, so the host re-initialises in seconds instead of
|
|
/// waiting ~90 s for the watchdog; the re-initialise brings the identical value back Good.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task A_hard_closed_connection_raises_ConnectionLost_once_and_the_reinit_recovers_in_seconds()
|
|
{
|
|
var ct = TestContext.Current.CancellationToken;
|
|
await using var rig = await OpcUaClientDriverWireTests.StartRigAsync("drv-hardclose", ct);
|
|
await using var proxy = TcpStallProxy.Start(new Uri(rig.EndpointUrl).Port);
|
|
OpcUaClientDriverWireTests.Publish(rig, OpcUaClientDriverWireTests.SpeedId, 10.0f);
|
|
|
|
await using var drv = OpcUaClientDriverWireTests.NewDriver(
|
|
rig, "wire-hardclose", endpointUrl: proxy.Through(rig.EndpointUrl), sessionTimeout: TimeSpan.FromSeconds(120));
|
|
var lost = new List<string>();
|
|
drv.ConnectionLost += (_, e) => { lock (lost) lost.Add(e.Reason); };
|
|
await drv.InitializeAsync("{}", ct);
|
|
var seen = new List<Seen>();
|
|
drv.OnDataChange += (_, e) =>
|
|
{
|
|
if (e.FullReference == OpcUaClientDriverWireTests.SpeedRef)
|
|
lock (seen) seen.Add(new Seen(e.Snapshot.StatusCode, e.Snapshot.Value, e.Snapshot.SourceTimestampUtc));
|
|
};
|
|
await drv.SubscribeAsync([OpcUaClientDriverWireTests.SpeedRef], TimeSpan.FromMilliseconds(100), ct);
|
|
await WaitAsync(() => { lock (seen) return seen.Any(s => s is { Status: 0u, Value: 10.0f }); }, "initial value");
|
|
var session = drv.Session.ShouldNotBeNull();
|
|
var keepAlives = new List<uint>();
|
|
session.KeepAlive += (_, e) => { lock (keepAlives) keepAlives.Add(e.Status?.StatusCode.Code ?? 0); };
|
|
|
|
// ── The upstream process goes away: every connection reset, new ones refused ──────────────────────────────
|
|
var killedAt = DateTime.UtcNow;
|
|
proxy.HardClose();
|
|
await WaitAsync(() => { lock (lost) return lost.Count > 0; },
|
|
"a sustained closed channel must raise ConnectionLost", TimeSpan.FromSeconds(15));
|
|
(DateTime.UtcNow - killedAt).ShouldBeLessThan(TimeSpan.FromSeconds(15), "seconds, not the watchdog's ~90 s");
|
|
lock (seen) seen.Count(s => s.Status == BadNoCommunication).ShouldBe(1, "the outage was published Bad first");
|
|
lock (keepAlives)
|
|
{
|
|
keepAlives.ShouldContain(0x80860000u, "BadSecureChannelClosed — the live-gate sequence");
|
|
keepAlives.ShouldContain(0x80AE0000u, "BadConnectionClosed — the live-gate sequence");
|
|
}
|
|
|
|
// The server is back — the session still exists on it — yet the SDK never reconnects by itself: no new
|
|
// connection reaches the proxy while further keep-alives fail. That is what makes the closed channel definitive.
|
|
proxy.Reopen();
|
|
var accepted = proxy.AcceptedConnections;
|
|
int kaAtReopen;
|
|
lock (keepAlives) kaAtReopen = keepAlives.Count;
|
|
await WaitAsync(() => { lock (keepAlives) return keepAlives.Count >= kaAtReopen + 4; }, "keep-alives keep failing");
|
|
proxy.AcceptedConnections.ShouldBe(accepted, "the SDK session never reopens a closed connection on its own");
|
|
drv.GetHealth().State.ShouldNotBe(DriverState.Healthy);
|
|
lock (lost) lost.Count.ShouldBe(1, "once per session, however many closed-channel keep-alives follow");
|
|
|
|
// ── The host's response (DriverInstanceActor: Reconnecting → ShutdownAsync + InitializeAsync → re-subscribe) ──
|
|
await drv.ShutdownAsync(ct);
|
|
await drv.InitializeAsync("{}", ct);
|
|
int before;
|
|
lock (seen) before = seen.Count;
|
|
await drv.SubscribeAsync([OpcUaClientDriverWireTests.SpeedRef], TimeSpan.FromMilliseconds(100), ct);
|
|
await WaitAsync(() => { lock (seen) return seen.Skip(before).Any(s => s is { Status: 0u, Value: 10.0f }); },
|
|
"the identical value must come back Good after the re-initialise");
|
|
(DateTime.UtcNow - killedAt).ShouldBeLessThan(TimeSpan.FromSeconds(60), "well under the watchdog's 90 s");
|
|
OpcUaClientDriverWireTests.Publish(rig, OpcUaClientDriverWireTests.SpeedId, 77.0f);
|
|
await WaitAsync(() => { lock (seen) return seen.Any(s => s is { Status: 0u, Value: 77.0f }); }, "a later change arrives");
|
|
drv.GetHealth().State.ShouldBe(DriverState.Healthy);
|
|
lock (lost) lost.Count.ShouldBe(1, "the healthy re-initialised session reports no loss");
|
|
}
|
|
}
|