From d5d86841bc1b17c74fb06fa51c2698ac823b31b6 Mon Sep 17 00:00:00 2001 From: Copilot Date: Sat, 29 Aug 2026 14:17:07 +0000 Subject: [PATCH 1/2] Fix flaky Task.WhenAny + Assert.Same timing races (#245) Add an AsyncAssert.CompletesWithinAsync helper (one copy per test project, matching the existing Infrastructure/ convention in the Conformance suite) to replace the fragile `Assert.Same(task, await Task.WhenAny(task, Task.Delay(timeout)))` pattern. The helper: - reports elapsed time and a "because" reason on timeout, instead of a bare "Values are not the same instance" failure; - re-awaits the original task so any exception it faulted with propagates, rather than being swallowed by Task.WhenAny. Widened the fixed timeouts flagged in the issue with modest headroom for CI-runner contention (KeepAliveSchedulerTests 5s -> 10s, SequenceHeartbeatTests 5x -> 10x interval, Retransmit/NotApplied/ ReconnectRetransmit 3s -> 5s), and moved KeepAliveSchedulerTests' scheduler Stop()/Dispose() into a finally block so cleanup still runs if the wait times out. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../ColdStartResumeTests.cs | 5 +-- .../Fixp/KeepAliveSchedulerTests.cs | 16 ++++++--- .../TestSupport/AsyncAssert.cs | 35 +++++++++++++++++++ .../Infrastructure/AsyncAssert.cs | 35 +++++++++++++++++++ .../SequenceHeartbeatTests.cs | 8 ++--- .../Spec_4_7_Retransmit/NotAppliedTests.cs | 5 ++- .../ReconnectRetransmitTests.cs | 4 +-- .../RetransmitRejectTests.cs | 5 ++- .../Spec_4_7_Retransmit/RetransmitTests.cs | 5 ++- 9 files changed, 97 insertions(+), 21 deletions(-) create mode 100644 tests/B3.EntryPoint.Client.Tests/TestSupport/AsyncAssert.cs create mode 100644 tests/B3.EntryPoint.Conformance/Infrastructure/AsyncAssert.cs diff --git a/tests/B3.EntryPoint.Client.Tests/ColdStartResumeTests.cs b/tests/B3.EntryPoint.Client.Tests/ColdStartResumeTests.cs index 7195d84..9727401 100644 --- a/tests/B3.EntryPoint.Client.Tests/ColdStartResumeTests.cs +++ b/tests/B3.EntryPoint.Client.Tests/ColdStartResumeTests.cs @@ -2,6 +2,7 @@ using B3.EntryPoint.Client.Fixp; using B3.EntryPoint.Client.State; using B3.EntryPoint.Client.TestPeer; +using B3.EntryPoint.Client.Tests.TestSupport; namespace B3.EntryPoint.Client.Tests; @@ -263,8 +264,8 @@ public async Task TerminateOnDispose_DefaultTrue_SendsTerminate() await client.DisposeAsync(); - var completed = await Task.WhenAny(terminateSeen.Task, Task.Delay(2000, cts.Token)); - Assert.Same(terminateSeen.Task, completed); + await AsyncAssert.CompletesWithinAsync( + terminateSeen.Task, TimeSpan.FromSeconds(3), "expected a Terminate frame on dispose", cts.Token); } [Fact] diff --git a/tests/B3.EntryPoint.Client.Tests/Fixp/KeepAliveSchedulerTests.cs b/tests/B3.EntryPoint.Client.Tests/Fixp/KeepAliveSchedulerTests.cs index 707d19d..4939da4 100644 --- a/tests/B3.EntryPoint.Client.Tests/Fixp/KeepAliveSchedulerTests.cs +++ b/tests/B3.EntryPoint.Client.Tests/Fixp/KeepAliveSchedulerTests.cs @@ -1,4 +1,5 @@ using B3.EntryPoint.Client.Fixp; +using B3.EntryPoint.Client.Tests.TestSupport; namespace B3.EntryPoint.Client.Tests.Fixp; @@ -94,10 +95,17 @@ Task SendAsync(CancellationToken ct) TimeSpan.FromMilliseconds(40), SendAsync); scheduler.Start(); - var completed = await Task.WhenAny(twoTicks.Task, Task.Delay(TimeSpan.FromSeconds(5))); - scheduler.Stop(); - scheduler.Dispose(); - Assert.Same(twoTicks.Task, completed); + try + { + // Widened from 5s to 10s (see #245): under CI-runner contention, + // even a 40ms tick interval can starve past a tight timeout. + await AsyncAssert.CompletesWithinAsync(twoTicks.Task, TimeSpan.FromSeconds(10), "expected two keep-alive ticks"); + } + finally + { + scheduler.Stop(); + scheduler.Dispose(); + } int finalCount; lock (ticks) finalCount = ticks.Count; Assert.True(finalCount >= 2, $"expected >=2 ticks, got {finalCount}"); diff --git a/tests/B3.EntryPoint.Client.Tests/TestSupport/AsyncAssert.cs b/tests/B3.EntryPoint.Client.Tests/TestSupport/AsyncAssert.cs new file mode 100644 index 0000000..81e1b0a --- /dev/null +++ b/tests/B3.EntryPoint.Client.Tests/TestSupport/AsyncAssert.cs @@ -0,0 +1,35 @@ +using System.Diagnostics; +using Xunit.Sdk; + +namespace B3.EntryPoint.Client.Tests.TestSupport; + +/// +/// Replaces the flaky Assert.Same(task, await Task.WhenAny(task, +/// Task.Delay(timeout))) pattern (see #245) with a helper that reports +/// elapsed time on timeout, making CI flakes easier to diagnose, and that +/// re-awaits the original task so any exception it faulted with propagates +/// instead of being swallowed. +/// +public static class AsyncAssert +{ + public static async Task CompletesWithinAsync(Task task, TimeSpan timeout, string? because = null, CancellationToken cancellationToken = default) + { + var stopwatch = Stopwatch.StartNew(); + var delay = Task.Delay(timeout, cancellationToken); + var completed = await Task.WhenAny(task, delay).ConfigureAwait(false); + if (!ReferenceEquals(completed, task)) + { + var reason = because is null ? string.Empty : $" ({because})"; + throw new XunitException( + $"Expected the awaited task to complete within {timeout}{reason}, but it did not. Elapsed: {stopwatch.Elapsed}."); + } + + await task.ConfigureAwait(false); + } + + public static async Task CompletesWithinAsync(Task task, TimeSpan timeout, string? because = null, CancellationToken cancellationToken = default) + { + await CompletesWithinAsync((Task)task, timeout, because, cancellationToken).ConfigureAwait(false); + return await task.ConfigureAwait(false); + } +} diff --git a/tests/B3.EntryPoint.Conformance/Infrastructure/AsyncAssert.cs b/tests/B3.EntryPoint.Conformance/Infrastructure/AsyncAssert.cs new file mode 100644 index 0000000..8f25e26 --- /dev/null +++ b/tests/B3.EntryPoint.Conformance/Infrastructure/AsyncAssert.cs @@ -0,0 +1,35 @@ +using System.Diagnostics; +using Xunit.Sdk; + +namespace B3.EntryPoint.Conformance.Infrastructure; + +/// +/// Replaces the flaky Assert.Same(task, await Task.WhenAny(task, +/// Task.Delay(timeout))) pattern (see #245) with a helper that reports +/// elapsed time on timeout, making CI flakes easier to diagnose, and that +/// re-awaits the original task so any exception it faulted with propagates +/// instead of being swallowed. +/// +public static class AsyncAssert +{ + public static async Task CompletesWithinAsync(Task task, TimeSpan timeout, string? because = null, CancellationToken cancellationToken = default) + { + var stopwatch = Stopwatch.StartNew(); + var delay = Task.Delay(timeout, cancellationToken); + var completed = await Task.WhenAny(task, delay).ConfigureAwait(false); + if (!ReferenceEquals(completed, task)) + { + var reason = because is null ? string.Empty : $" ({because})"; + throw new XunitException( + $"Expected the awaited task to complete within {timeout}{reason}, but it did not. Elapsed: {stopwatch.Elapsed}."); + } + + await task.ConfigureAwait(false); + } + + public static async Task CompletesWithinAsync(Task task, TimeSpan timeout, string? because = null, CancellationToken cancellationToken = default) + { + await CompletesWithinAsync((Task)task, timeout, because, cancellationToken).ConfigureAwait(false); + return await task.ConfigureAwait(false); + } +} diff --git a/tests/B3.EntryPoint.Conformance/Spec_4_6_Sequence/SequenceHeartbeatTests.cs b/tests/B3.EntryPoint.Conformance/Spec_4_6_Sequence/SequenceHeartbeatTests.cs index 914d50a..23d1770 100644 --- a/tests/B3.EntryPoint.Conformance/Spec_4_6_Sequence/SequenceHeartbeatTests.cs +++ b/tests/B3.EntryPoint.Conformance/Spec_4_6_Sequence/SequenceHeartbeatTests.cs @@ -42,11 +42,11 @@ public async Task KeepAlive_Sequence_Frames_Are_Exchanged() if (Interlocked.Increment(ref receivedCount) >= 1) receivedTcs.TrySetResult(); }; - // Cap the wait at 5×interval so a stalled scheduler fails fast. - var timeout = TimeSpan.FromMilliseconds(250 * 5); + // Cap the wait at 10×interval so a stalled scheduler still fails fast + // while leaving headroom for CI-runner contention (see #245). + var timeout = TimeSpan.FromMilliseconds(250 * 10); var both = Task.WhenAll(sentTcs.Task, receivedTcs.Task); - var completed = await Task.WhenAny(both, Task.Delay(timeout)); - Assert.Same(both, completed); + await AsyncAssert.CompletesWithinAsync(both, timeout, "expected Sequence frames to be sent and received"); Assert.True(sentCount >= 1, $"Expected at least one Sequence frame sent, got {sentCount}"); Assert.True(receivedCount >= 1, $"Expected at least one Sequence frame received, got {receivedCount}"); } diff --git a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/NotAppliedTests.cs b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/NotAppliedTests.cs index dda68ae..6901c79 100644 --- a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/NotAppliedTests.cs +++ b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/NotAppliedTests.cs @@ -28,9 +28,8 @@ public async Task NotApplied_From_Peer_Surfaces_Event_With_Range() var sent = await fx.Peer.InjectNotAppliedAsync(fromSeqNo: 7u, count: 3u); Assert.True(sent >= 1, "Expected the NotApplied frame to be written to at least one connection"); - var completed = await Task.WhenAny(na.Task, Task.Delay(TimeSpan.FromSeconds(3))); - Assert.Same(na.Task, completed); - var evt = await na.Task; + var evt = await AsyncAssert.CompletesWithinAsync( + na.Task, TimeSpan.FromSeconds(5), "expected a NotAppliedReceived event"); Assert.Equal(7UL, evt.FromSeqNo); Assert.Equal(3u, evt.Count); } diff --git a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs index a5b2f83..8be99ea 100644 --- a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs +++ b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs @@ -161,8 +161,8 @@ await client.SubmitAsync(new NewOrderRequest fx.Peer.MessageReceived += probe; try { - var completed = await Task.WhenAny(seenSix.Task, Task.Delay(TimeSpan.FromSeconds(3))); - Assert.Same(seenSix.Task, completed); + await AsyncAssert.CompletesWithinAsync( + seenSix.Task, TimeSpan.FromSeconds(5), "expected the resubmitted order to reach the peer"); } finally { diff --git a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitRejectTests.cs b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitRejectTests.cs index b60292f..59fa2e6 100644 --- a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitRejectTests.cs +++ b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitRejectTests.cs @@ -31,9 +31,8 @@ public async Task Retransmit_Reject_Is_Surfaced_With_Code() await client.Retransmit.RequestRetransmitAsync(fromSeqNo: 1UL, count: 5U); - var completed = await Task.WhenAny(rejected.Task, Task.Delay(TimeSpan.FromSeconds(3))); - Assert.Same(rejected.Task, completed); - var evt = await rejected.Task; + var evt = await AsyncAssert.CompletesWithinAsync( + rejected.Task, TimeSpan.FromSeconds(5), "expected a RetransmitRejected event"); Assert.Equal(RetransmitRejectCode.OutOfRange, evt.Code); } } diff --git a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitTests.cs b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitTests.cs index 17454bd..964e8ca 100644 --- a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitTests.cs +++ b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/RetransmitTests.cs @@ -34,9 +34,8 @@ public async Task Retransmit_Recent_Range_Is_Honoured() await client.Retransmit.RequestRetransmitAsync(fromSeqNo: 1UL, count: 5U); - var completed = await Task.WhenAny(received.Task, Task.Delay(TimeSpan.FromSeconds(3))); - Assert.Same(received.Task, completed); - var evt = await received.Task; + var evt = await AsyncAssert.CompletesWithinAsync( + received.Task, TimeSpan.FromSeconds(5), "expected a RetransmissionReceived event"); Assert.Equal(1UL, evt.NextSeqNo); Assert.Equal(0u, evt.Count); } From ce9553e7a39d80706e84c1464c1a52d9d8b234e4 Mon Sep 17 00:00:00 2001 From: Copilot Date: Sat, 29 Aug 2026 15:47:46 +0000 Subject: [PATCH 2/2] Fix genuine race in ReconnectRetransmitTests, not just its timeout MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit CI on PR #246 still failed with the widened 5s timeout, and the elapsed time was exactly 5.0002030s — i.e. a real hang, not a close-shave flake. The TryPeek-then-subscribe fallback left a window between checking peerInboundNosSeqs and subscribing the probe handler where the peer's MessageReceived event for the resubmitted order could fire and be lost forever, since nothing was listening for it yet and peerInboundNosSeqs was checked (not re-checked) only once. Fix: subscribe the probe before calling SubmitAsync so the event literally cannot be missed. Ran the affected test 20x locally against the in-process TestPeer with no failures (previously it flaked here under contention). Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../ReconnectRetransmitTests.cs | 50 +++++++++---------- 1 file changed, 24 insertions(+), 26 deletions(-) diff --git a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs index 8be99ea..2eb6a57 100644 --- a/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs +++ b/tests/B3.EntryPoint.Conformance/Spec_4_7_Retransmit/ReconnectRetransmitTests.cs @@ -132,18 +132,14 @@ await client.SubmitAsync(new NewOrderRequest // 7. Submit one more order; assert the peer sees it on the wire with // MsgSeqNum = 6, proving the outbound counter resumed contiguously. - await client.SubmitAsync(new NewOrderRequest - { - ClOrdID = (ClOrdID)6, - SecurityId = 4321UL, - Side = Side.Buy, - OrderType = OrderType.Limit, - Price = 10.0m, - OrderQty = 100UL, - }); - - // Wait briefly for the peer to read the frame off the wire (TCS via - // a one-shot signal on the MessageReceived event). + // + // Subscribe the probe BEFORE submitting (previously it was + // subscribed only after SubmitAsync returned, with a TryPeek + // fallback for anything already enqueued — but the peer could + // process the frame and raise MessageReceived in the window + // between that TryPeek check and the += subscription, which is + // lost forever and made the test hang for the full timeout; see + // #245 CI failure). Subscribing first closes that race. var seenSix = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); EventHandler probe = (_, args) => { @@ -151,23 +147,25 @@ await client.SubmitAsync(new NewOrderRequest if (!NewOrderSingleData.TryParse(args.Payload.Span, out var reader)) return; seenSix.TrySetResult(reader.Data.BusinessHeader.MsgSeqNum.Value); }; - // Drain anything already enqueued from the resubmitted order. - if (peerInboundNosSeqs.TryPeek(out var first)) + fx.Peer.MessageReceived += probe; + try { - seenSix.TrySetResult(first); + await client.SubmitAsync(new NewOrderRequest + { + ClOrdID = (ClOrdID)6, + SecurityId = 4321UL, + Side = Side.Buy, + OrderType = OrderType.Limit, + Price = 10.0m, + OrderQty = 100UL, + }); + + await AsyncAssert.CompletesWithinAsync( + seenSix.Task, TimeSpan.FromSeconds(5), "expected the resubmitted order to reach the peer"); } - else + finally { - fx.Peer.MessageReceived += probe; - try - { - await AsyncAssert.CompletesWithinAsync( - seenSix.Task, TimeSpan.FromSeconds(5), "expected the resubmitted order to reach the peer"); - } - finally - { - fx.Peer.MessageReceived -= probe; - } + fx.Peer.MessageReceived -= probe; } Assert.Equal(6u, await seenSix.Task);