Skip to content

Make server initialization log assertions thread-safe - #85899

Merged
mwiemer-microsoft merged 1 commit into
mainfrom
mwiemer-server-initialization-log-race
Oct 2, 2026
Merged

mwiemer-microsoft merged 1 commit into
mainfrom
mwiemer-server-initialization-log-race

Conversation

@mwiemer-microsoft

@mwiemer-microsoft mwiemer-microsoft commented Oct 2, 2026 •

Copy link
Copy Markdown
Member

AI-generated:

Summary

Extract the pre-existing test race discussed in #85776 into a separate fix against main.

TestUpdateLogLevelAppliesToNextWindowLogMessagesAsync collects window/logMessage callbacks in a mutable List<string> and reads it after disposing the server. The real shutdown callback can still insert a message after disposal returns, including during assertion enumeration.

Use ConcurrentQueue<string> and take one ToArray() snapshot for the four existing membership assertions. The queue retains enqueue order for debugging, unlike a concurrent bag. No product behavior, callback scheduling, xUnit imports, or completion-source options change.

Controlled reproduction on main

Base: d95fce4d81f2809e06449b1413752764ccc2bd45 (xUnit v2).

A temporary test used the actual CreateLanguageServerAsync server and its LogMessageReceived event, not a fabricated background producer:

  1. Block the real Shutting down notification callback immediately before adding its message to the collection.
  2. Await server.DisposeAsync(). It completes while that callback is still blocked.
  3. Obtain the collection enumerator, then release the callback and await its insertion.
  4. Advance the enumerator.

With the original List<string>, this fails with:

Server disposal completed while the shutdown log callback was blocked before List.Add.
Shutdown callback mutated the collection after disposal and after enumeration began.
System.InvalidOperationException: Collection was modified; enumeration operation may not execute.
   at System.Collections.Generic.List`1.Enumerator.MoveNext()

With the queue and a snapshot obtained at the same point, the controlled interleaving passes. This proves a permitted failing interleaving on main; it does not establish the origin of the earlier Linux CI failure. The installed StreamJsonRpc 2.26.114 also documents that local methods may outlive disposal/Completion and that DispatchCompletion is the separate dispatch-draining primitive. The current client harness does not await that primitive. xUnit v2's collection membership assertions enumerate the collection.

Temporary failing probe (add to ServerInitializationTests to reproduce on the base commit)
[Fact]
public async Task TestShutdownLogCollectionRaceReproAsync()
{
    var logMessages = new List<string>();
    var callbackEntered = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
    var callbackCompleted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
    using var releaseCallback = new ManualResetEventSlim();
    var server = await CreateLanguageServerAsync();
    Task? disposal = null;
    server.LogMessageReceived += logMessage =>
    {
        if (logMessage.Message.Contains("Shutting down", StringComparison.Ordinal))
        {
            callbackEntered.TrySetResult();
            if (!releaseCallback.Wait(TimeSpan.FromSeconds(30)))
            {
                callbackCompleted.TrySetException(new TimeoutException("Shutdown callback was not released."));
                return;
            }

            logMessages.Add(logMessage.Message);
            callbackCompleted.TrySetResult();
        }
    };

    try
    {
        disposal = server.DisposeAsync().AsTask();
        await callbackEntered.Task.WaitAsync(TimeSpan.FromSeconds(30));
        await disposal.WaitAsync(TimeSpan.FromSeconds(30));
        TestOutputHelper.WriteLine("Server disposal completed while the shutdown log callback was blocked before List.Add.");

        using var enumerator = logMessages.GetEnumerator();
        releaseCallback.Set();
        await callbackCompleted.Task.WaitAsync(TimeSpan.FromSeconds(30));
        TestOutputHelper.WriteLine("Shutdown callback mutated the collection after disposal and after enumeration began.");
        Assert.False(enumerator.MoveNext());
    }
    finally
    {
        releaseCallback.Set();
        if (disposal is not null)
        {
            await disposal.WaitAsync(TimeSpan.FromSeconds(30));
        }

        await callbackCompleted.Task.WaitAsync(TimeSpan.FromSeconds(30));
    }
}

For the passing variant, use ConcurrentQueue<string>/Enqueue and obtain the enumerator from the ToArray() snapshot instead. The temporary probe was removed from the product diff; this description preserves it for reproduction.

Validation

  • Baseline ServerInitializationTests: 3 passed.
  • Controlled original-list probe: failed with the exception above.
  • Controlled queue/snapshot probe plus initialization tests: 4 passed.
  • Final project build with RunAnalyzersDuringBuild=true and full LanguageServer unit-test run: 394 passed, 1 skipped, 0 failed.
  • Changed-file whitespace formatting and git diff --check passed.
dotnet test src\LanguageServer\Microsoft.CodeAnalysis.LanguageServer.UnitTests\Microsoft.CodeAnalysis.LanguageServer.UnitTests.csproj --no-restore --filter FullyQualifiedName~ServerInitializationTests -v quiet -p:RunAnalyzersDuringBuild=true
dotnet test src\LanguageServer\Microsoft.CodeAnalysis.LanguageServer.UnitTests\Microsoft.CodeAnalysis.LanguageServer.UnitTests.csproj --no-restore -v quiet -p:RunAnalyzersDuringBuild=true
Microsoft Reviewers: Open in CodeFlow

Use an ordered concurrent queue and a stable snapshot so late shutdown log callbacks cannot mutate a List during assertions.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
@azure-pipelines

Copy link
Copy Markdown
Azure Pipelines:
Successfully started running 2 pipeline(s).
There may be pipelines that require an authorized user to comment /azp run to run.

@mwiemer-microsoft
mwiemer-microsoft marked this pull request as ready for review October 2, 2026 19:46
@mwiemer-microsoft
mwiemer-microsoft requested a review from a team as a code owner October 2, 2026 19:46
Copilot AI balanced review requested due to automatic review settings October 2, 2026 19:46
@mwiemer-microsoft
mwiemer-microsoft enabled auto-merge (squash) October 2, 2026 19:46

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Copilot review overview

🟢 Approval recommended

The focused change safely resolves the demonstrated race without altering product behavior or test intent.

Review effort: Balanced
Findings: None

What changed in this PR

Makes Language Server log assertions thread-safe by snapshotting concurrently received messages before assertion enumeration.

Changes:

  • Replaces List<string> with ConcurrentQueue<string>.
  • Runs existing assertions against one stable array snapshot.
File Description
ServerInitializationTests.cs Prevents concurrent callback mutations from invalidating assertion enumeration.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants