Skip to content

Fix race condition in FakeLogCollector async enumeration test#7300

Merged
stephentoub merged 3 commits intomainfrom
copilot/fix-flaky-getlogs-test
Feb 14, 2026
Merged

Fix race condition in FakeLogCollector async enumeration test#7300
stephentoub merged 3 commits intomainfrom
copilot/fix-flaky-getlogs-test

Conversation

Copy link
Contributor

Copilot AI commented Feb 14, 2026

Fix flaky test race condition in FakeLogCollectorTests

  • Understand the problem: race condition where enumerator #2 may not have consumed logs A and B before Clear() is called
  • Add TaskCompletionSource to signal when enumerator #2 has processed both "A" and "B" (moveNextCounter == 2)
  • Modify the lambda passed to AwaitSequence for abcSequenceTask to set the TaskCompletionSource
  • Add await for the TaskCompletionSource before calling Clear()
  • Run the specific test to verify the fix works (5 runs - all passed)
  • Verify no other tests are broken (all 9 FakeLogCollectorTests passed)
  • Fix .NET Framework compatibility by using TaskCompletionSource instead of non-generic version
Original prompt

Bug

The test GetLogsAsync_RegardlessOfClearDuringWait_SuppliesNextLogWhenRecorded(clearIsCalledDuringWait: True) is flaky due to a race condition.

Root Cause

The test creates two async enumerators over FakeLogCollector.GetLogsAsync():

After emitting logs "A" and "B", the test awaits abSequenceTask (enumerator #1) completing, then immediately calls fakeLogCollector.Clear(). However, enumerator #1 completing does not guarantee enumerator #2 has also consumed "A" and "B" — they run on separate thread pool threads.

When Clear() is called before enumerator #2 finishes processing "A" and "B":

  1. Clear() empties _records and increments _recordCollectionVersion
  2. When enumerator Adding NullLogging project #2 resumes, MoveNextAsync detects the version change and resets _index to 0
  3. The only record available is "C" (added after the clear), but enumerator Adding NullLogging project #2 still expects "A" or "B" next
  4. "C" doesn't match → enumerator Adding NullLogging project #2 blocks forever waiting for a record that will never come
  5. AssertAwaitingTaskCompleted(abcSequenceTask) times out after 5 seconds

Fix

In the test file test/Libraries/Microsoft.Extensions.Diagnostics.Testing.Tests/Logging/FakeLogCollectorTests.LogEnumeration.cs, in the GetLogsAsync_RegardlessOfClearDuringWait_SuppliesNextLogWhenRecorded method:

Add a TaskCompletionSource that signals when enumerator #2 has processed both "A" and "B" (i.e., when moveNextCounter reaches 2), and await it before calling Clear().

Change the code from:

var abcSequenceTask = AwaitSequence(
    new Queue<string>(["A", "B", "C"]),
    fromIndex: 0,
    fakeLogCollector,
    null,
    cancellationToken: CancellationToken.None,
    () => Interlocked.Increment(ref moveNextCounter));

EmitLogs(logger, ["A", "B"], null);
await AssertAwaitingTaskCompleted(abSequenceTask); // checkpoint to not clear, before A, B is processed

if (clearIsCalledDuringWait)
{
    fakeLogCollector.Clear();
}

To:

var abcProcessedAB = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);

var abcSequenceTask = AwaitSequence(
    new Queue<string>(["A", "B", "C"]),
    fromIndex: 0,
    fakeLogCollector,
    null,
    cancellationToken: CancellationToken.None,
    () =>
    {
        if (Interlocked.Increment(ref moveNextCounter) == 2)
        {
            abcProcessedAB.TrySetResult();
        }
    });

EmitLogs(logger, ["A", "B"], null);
await AssertAwaitingTaskCompleted(abSequenceTask); // checkpoint to not clear, before A, B is processed
await AssertAwaitingTaskCompleted(abcProcessedAB.Task); // ensure enumerator #2 has also consumed A and B

if (clearIsCalledDuringWait)
{
    fakeLogCollector.Clear();
}

This ensures enumerator #2 has definitively consumed "A" and "B" before Clear() wipes the records and triggers the version-change index reset. The fix reuses the existing AssertAwaitingTaskCompleted helper which provides a 5-second timeout.

Only the test file needs to be changed. The production FakeLogCollector code is correct.

This pull request was created from Copilot chat.


💬 We'd love your input! Share your thoughts on Copilot coding agent in our 2 minute survey.

Microsoft Reviewers: Open in CodeFlow

Copilot AI changed the title [WIP] Fix flaky GetLogsAsync test due to race condition Fix race condition in FakeLogCollector async enumeration test Feb 14, 2026
Copilot AI requested a review from stephentoub February 14, 2026 12:43
@stephentoub
Copy link
Member

@copilot

Build FAILED.

D:\a\_work\1\s\test\Libraries\Microsoft.Extensions.Diagnostics.Testing.Tests\Logging\FakeLogCollectorTests.LogEnumeration.cs(101,34): error CS0305: Using the generic type 'TaskCompletionSource<TResult>' requires 1 type arguments [D:\a\_work\1\s\test\Libraries\Microsoft.Extensions.Diagnostics.Testing.Tests\Microsoft.Extensions.Diagnostics.Testing.Tests.csproj::TargetFramework=net462]
    0 Warning(s)
    1 Error(s)

Copy link
Contributor Author

Copilot AI commented Feb 14, 2026

@copilot

Build FAILED.

...

Fixed in c12560b by using TaskCompletionSource<bool> instead of the non-generic version for .NET Framework 4.6.2 compatibility.

@stephentoub stephentoub marked this pull request as ready for review February 14, 2026 14:17
@stephentoub stephentoub requested a review from a team as a code owner February 14, 2026 14:17
Copilot AI review requested due to automatic review settings February 14, 2026 14:17
Copy link
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR fixes a flaky test in FakeLogCollectorTests that was failing due to a race condition in concurrent async enumeration. The test creates two enumerators that process logs asynchronously, but the original code only waited for the first enumerator to complete before calling Clear(), which could cause the second enumerator to fail if it hadn't yet consumed the expected logs.

Changes:

  • Added synchronization to ensure both concurrent async enumerators have consumed logs A and B before Clear() is called
  • Used TaskCompletionSource<bool> with RunContinuationsAsynchronously for proper async coordination and .NET Framework compatibility

@stephentoub stephentoub enabled auto-merge (squash) February 14, 2026 15:17
@Demo30
Copy link
Contributor

Demo30 commented Feb 14, 2026

Adding my own summary as it took me a while to properly understand: The failure occurs in failing the assertion AssertAwaitingTaskCompleted where a timeout (5s) is hit instead of expected abc task. The original logic awaited first enumerator's "A","B" processing and proceeded with calling Clear(). However that doesn't mean the second enumerator (abc) has consumed both "A" and "B" before Clear() is called, therefore Clear() may be called early (e.g. after "A" is processed) and the sequence may never be fulfilled (never getting "B"). This proposal fixes that by making sure the Clear() is called when both enumerators have consumed both "A" and "B"

Test failure report

[xUnit.net 00:00:01.26]         Sequence awaiter satisfied at 02/10/2026 19:56:43
[xUnit.net 00:00:06.66]     Microsoft.Extensions.Logging.Testing.Test.Logging.FakeLogCollectorTests.GetLogsAsync_RegardlessOfClearDuringWait_SuppliesNextLogWhenRecorded(clearIsCalledDuringWait: True) [FAIL]
[xUnit.net 00:00:06.66]       Assert.Equal() Failure: Values differ
[xUnit.net 00:00:06.66]       Expected: Task { Status = RanToCompletion }
[xUnit.net 00:00:06.66]       Actual:   Task<ValueTuple<bool, int>,<AwaitSequence>d__12> { Status = WaitingForActivation }

@stephentoub stephentoub merged commit 54a9c12 into main Feb 14, 2026
12 checks passed
@stephentoub stephentoub deleted the copilot/fix-flaky-getlogs-test branch February 14, 2026 20:01
@github-actions github-actions bot locked and limited conversation to collaborators Mar 17, 2026
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants