dotnet / dotnet/msbuild

BuildCheck: intermittent `InvalidOperationException: Collection was modified` in `BuildCheckManager.StartProjectRequest`

Open
#14,644 0 comments 1 reaction 2 assignees Claimed by @ViktorHofer View on GitHub
Dominant language
C#
Stars
5.5k
Forks
1.5k
Avg merge
1d 8h
Merged PRs (30d)
141

Description

### Issue Description

Building a large solution with `-check` intermittently kills MSBuild with an unhandled
`System.InvalidOperationException: Collection was modified; enumeration operation may not execute.`
thrown from `BuildCheckManagerProvider.BuildCheckManager.StartProjectRequest`.

It happens rarely, but it keeps happening. Below are two occurrences I still have the logs for
(2026-07-27 and 2026-08-04); they are samples rather than the complete set. Conveniently they show
the two different shapes the failure takes:

* directly on a `RequestBuilder` thread (unhandled exception, build fails), and
* on the logging thread, where it is wrapped into `InternalLoggerException` and brings the
node down with `MSB4166: The child node "1" exited prematurely`.

Both land on the same line of `StartProjectRequest`, and I believe both are the same defect: the
`_deferredEvalDiagnostics` field is a plain `Dictionary>` that is read,
enumerated, cleared and written from more than one thread without any synchronization. Analysis
below.

Note: our CI runs a German SDK, so a few message texts in the logs are localized. I have added
English translations in brackets; the exception messages and stack frames are untouched.

### Steps to Reproduce

I could not produce a small standalone repro — it is a race and it fires rarely. What the failing
builds have in common:

```
dotnet build "MySolution.slnf" --configuration debug -graphBuild -check
```

* ~311 projects in the solution filter, ~321 of them multi-targeted.
* TFM fan-out per project: `net10.0`, `net10.0-windows`, `net10.0-android`, `net10.0-ios`,
`net10.0-windows10.0.19041.0` (plus a few `netstandard2.0`/`netstandard2.1`/`net48`).
* `-graphBuild` plus default parallelism on a many-core CI agent, so a lot of `ProjectStarted`
traffic in flight at once.
* Evaluation-time BuildCheck warnings are actually being produced (`BC0202`, see the log excerpt
below). Those are exactly the events that end up in `_deferredEvalDiagnostics`, so the list that
`StartProjectRequest` enumerates is non-empty in these builds.

Both captured failures were on the same multi-targeted project, but on different target frameworks
(`net10.0-windows10.0.19041.0` and `net10.0-android`).

Based on the analysis below, an intentional repro would want: a project that emits an
evaluation-time check warning (BC0201/BC0202), built as part of a large `-graphBuild -check` build
with high parallelism, so that a `RequestBuilder` thread and the logging thread enter
`StartProjectRequest` for the same evaluation id at the same time.

**I have no binlog for the occurrences above** — the build directories are cleaned unconditionally
after every CI run. I can arrange to capture diagnostics on a future occurrence though, so just say
what would help most and I will wire it up and report back.

### Expected Behavior

`-check` does not crash the build.

### Actual Behavior

**Failure 1 — 2026-08-04, on a `RequestBuilder` thread.**
Project: `D:\agent\_work\1\s\Contoso.App\Shared\Contoso.App.Shared.csproj::TargetFramework=net10.0-windows10.0.19041.0`

```
MSBUILD : error : Dies ist eine nicht behandelte Ausnahme in MSBuild. RUFEN SIE EIN VORHANDENES
PROBLEM AUF, ODER ERSTELLEN SIE EIN NEUES UNTER https://aka.ms/msbuild/unhandled
[= This is an unhandled exception in MSBuild ...]
MSBUILD : error : System.InvalidOperationException: Collection was modified; enumeration operation may not execute.
MSBUILD : error : at System.Collections.Generic.List`1.Enumerator.MoveNext()
MSBUILD : error : at Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckManagerProvider.BuildCheckManager.StartProjectRequest(ICheckContext checkContext, String projectFullPath)
MSBUILD : error : at Microsoft.Build.BackEnd.RequestBuilder.HandleProjectStarted(IBuildCheckManager buildCheckManager)
MSBUILD : error : at Microsoft.Build.BackEnd.RequestBuilder.BuildProject()
MSBUILD : error : at Microsoft.Build.BackEnd.RequestBuilder.RequestThreadProc(Boolean setThreadParameters)
```

**Failure 2 — 2026-07-27, on the logging thread.**
Project: `D:\agent\_work\2\s\Contoso.App\Shared\Contoso.App.Shared.csproj::TargetFramework=net10.0-android`

The immediately preceding line in the log is a deferred evaluation-time check warning for that very
project — i.e. `_deferredEvalDiagnostics` demonstrably had entries:

```
...\sdk\10.0.302\Sdks\Microsoft.NET.Sdk.WindowsDesktop\targets\Microsoft.NET.Sdk.WindowsDesktop.WindowsForms.props(15,14):
warning BC0202: https://aka.ms/buildcheck/codes#BC0202 - Eigenschaft: "ImplicitUsings" wurde zuerst
bei "D:\agent\_work\2\s\Contoso.App\Shared\Contoso.App.Shared.csproj (4,5)" deklariert/initialisiert,
die vor der Initialisierung verwendet wurde.
[= Property "ImplicitUsings" was first declared/initialized at ..., and was used before initialization.]
```

```
MSBUILD : error MSB4166: Der untergeordnete Knoten "1" wurde vorzeitig beendet. Vorgang zum Herunterfahren wird ausgeführt.
[= The child node "1" exited prematurely. Shutting down.]
Microsoft.Build.Exceptions.InternalLoggerException: Der Buildvorgang wurde aufgrund eines unerwarteten Protokollierungsfehlers unerwartet beendet.
---> Microsoft.Build.Exceptions.InternalLoggerException: Der Buildvorgang wurde aufgrund eines unerwarteten Protokollierungsfehlers unerwartet beendet.
---> System.InvalidOperationException: Collection was modified; enumeration operation may not execute.
at System.Collections.Generic.List`1.Enumerator.MoveNext()
at Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckManagerProvider.BuildCheckManager.StartProjectRequest(ICheckContext checkContext, String projectFullPath)
at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(BuildEventArgs buildEvent)
--- End of inner exception stack trace ---
at Microsoft.Build.Exceptions.InternalLoggerException.Throw(Exception innerException, BuildEventArgs e, String messageResourceName, Boolean initializationException, String[] messageArgs)
at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(BuildEventArgs buildEvent)
at Microsoft.Build.Experimental.BuildCheck.Infrastructure.BuildCheckForwardingLogger.EventSource_AnyEventRaised(Object sender, BuildEventArgs buildEvent)
at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(BuildEventArgs buildEvent)
--- End of inner exception stack trace ---
at Microsoft.Build.Exceptions.InternalLoggerException.Throw(Exception innerException, BuildEventArgs e, String messageResourceName, Boolean initializationException, String[] messageArgs)
at Microsoft.Build.BackEnd.Logging.EventSourceSink.RaiseAnyEvent(BuildEventArgs buildEvent)
at Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(BuildEventArgs eventArg)
at Microsoft.Build.BackEnd.Logging.LoggingService.RouteBuildEvent(Object loggingEvent)
at Microsoft.Build.BackEnd.Logging.LoggingService.LoggingEventProcessor(Object loggingEvent)
--- End of stack trace from previous location ---
at Microsoft.Build.Execution.BuildManager.BuildGraph(ProjectGraph projectGraph, IReadOnlyDictionary`2 targetsPerNode, GraphBuildRequestData graphBuildRequestData)
at Microsoft.Build.Execution.BuildManager.ExecuteGraphBuildScheduler(GraphBuildSubmission submission)
at Microsoft.Build.Execution.BuildManager.<>c__DisplayClass94_0.b__0()
```

### Analysis

> **Disclaimer:** I put this analysis together with the help of an AI assistant, working from the
> two stack traces above and the current `main` sources. I have reviewed it and it is consistent
> with everything I see in the logs, but I have not confirmed the race in a debugger — please read
> it as a well-supported hypothesis, not a verified diagnosis.

(Line numbers are from `src/Build/BuildCheck/Infrastructure/BuildCheckManagerProvider.cs` on `main`
as of 2026-08-05.)

The deferred evaluation diagnostics are held in a **non-concurrent** dictionary of **non-concurrent**
lists — everything else nearby in this class is a `ConcurrentDictionary`/`ConcurrentBag`, and there
is no `lock` anywhere in the class:

```csharp
// L662
private readonly Dictionary> _deferredEvalDiagnostics = new();
```

Writer — `IResultReporter.ReportResult` (L679-L706), for every evaluation-time
`BuildWarningEventArgs` that does not yet have an instance id:

```csharp
if (!_deferredEvalDiagnostics.TryGetValue(eventArgs.BuildEventContext.EvaluationId, out var list))
{
list = [];
_deferredEvalDiagnostics[eventArgs.BuildEventContext.EvaluationId] = list;
}

list.Add(eventArgs);
```

Reader — `StartProjectRequest` (L643-L660), which enumerates that list, dispatches each event
(re-entering the logging service in the process), then clears it and removes the entry:

```csharp
if (_deferredEvalDiagnostics.TryGetValue(buildEventContext.EvaluationId, out var list))
{
foreach (BuildEventArgs deferredArgs in list) // <-- List.Enumerator.MoveNext() throws here
{
deferredArgs.BuildEventContext = deferredArgs.BuildEventContext!.WithInstanceIdAndContextId(buildEventContext);
checkContext.DispatchBuildEvent(deferredArgs);
}
list.Clear();
_deferredEvalDiagnostics.Remove(buildEventContext.EvaluationId);
}
```

`StartProjectRequest` has **two call sites, on two different threads**:

1. `RequestBuilder.HandleProjectStarted` — the `RequestBuilder` thread (this is stack 1 above).
Note that it logs the `ProjectStarted` event *and then* calls `StartProjectRequest` itself:

```csharp
// RequestBuilder.cs, HandleProjectStarted
loggingService?.LogProjectStarted(args); // -> asynchronous logging queue

buildCheckManager?.StartProjectRequest(
new CheckLoggingContext(_nodeLoggingContext.LoggingService, _projectLoggingContext!.BuildEventContext),
_requestEntry.RequestConfiguration.ProjectFullPath);
```

2. `BuildCheckBuildEventHandler.HandleProjectStartedRequest`, reached from
`BuildCheckConnectorLogger.EventSource_AnyEventRaised` -> `EventSourceSink.RaiseAnyEvent` ->
`LoggingService.LoggingEventProcessor` — the logging thread (this is stack 2 above; the two
one-line methods in between are inlined in release builds):

```csharp
private void HandleProjectStartedRequest(ProjectStartedEventArgs eventArgs)
=> _buildCheckManager.StartProjectRequest(
_checkContextFactory.CreateCheckContext(eventArgs.BuildEventContext!),
eventArgs!.ProjectFile!);
```

Because `args` in `HandleProjectStarted` is created from the same `ProjectLoggingContext` that is
passed to the direct call, **both invocations carry the same `BuildEventContext`, therefore the same
`EvaluationId`, therefore the same `List` instance** — and they can run
concurrently, since `LogProjectStarted` only queues the event before the `RequestBuilder` thread
proceeds into `StartProjectRequest`.

So there are (at least) two ways to invalidate a live enumerator, both consistent with the observed
stacks:

* Two concurrent `StartProjectRequest` calls for the same evaluation id: one is inside the
`foreach`, the other reaches `list.Clear()`. Whichever thread is enumerating throws — the
`RequestBuilder` thread in stack 1, the logging thread in stack 2.
* A concurrent `ReportResult` doing `list.Add(...)` for an evaluation id whose list is currently
being enumerated. `StartProjectRequest` removes the dictionary entry only *after* the loop, so a
late-arriving evaluation warning still finds and appends to the list being iterated.

A corollary of the same race, even when it does not throw: if both call sites get through the
`foreach` before either reaches `Clear()`, the deferred evaluation warnings are dispatched twice, so
duplicated `BC02xx` warnings would be another possible symptom.

### Suggested fix

Guard `_deferredEvalDiagnostics` (and the lists inside it) with a lock. Dispatch re-enters the
logging service, so it should happen *outside* the lock — taking the list out of the dictionary
atomically and then enumerating a private reference does both, and also removes the double-dispatch:

```csharp
List? list;
lock (_deferredEvalDiagnosticsLock)
{
if (_deferredEvalDiagnostics.Remove(buildEventContext.EvaluationId, out list) is false)
{
return;
}
}

foreach (BuildEventArgs deferredArgs in list)
{
deferredArgs.BuildEventContext = deferredArgs.BuildEventContext!.WithInstanceIdAndContextId(buildEventContext);
checkContext.DispatchBuildEvent(deferredArgs);
}
```

with the matching `lock` around the `TryGetValue`/`Add` in `ReportResult`. (Whether the *second*
`StartProjectRequest` call for the same project is intended at all might be worth a separate look —
with the fix above the loser of the race would simply find nothing to dispatch.)

### Versions & Configurations

* .NET SDK **10.0.302** (`global.json` pins `10.0.300` with `"rollForward": "latestMinor"`),
MSBuild as bundled with that SDK.
* Windows, Azure DevOps self-hosted agent, German (de-DE) UI culture.
* Command line:
`dotnet build "MySolution.slnf" --configuration debug -graphBuild -check`
* ~311 projects, mostly multi-targeted (see *Steps to Reproduce*).

### Regression?

Not to my knowledge — this looks like it has been there since the deferred-diagnostics logic was
introduced, and `main` still declares `_deferredEvalDiagnostics` as a plain `Dictionary` today. We
only started using `-check` recently, so I cannot say whether an older SDK behaves differently.

### Related

* #11326 — *Enabling BuildCheck causes error MSB4166: Child node "1" exited prematurely* (closed).
Same area and same MSB4166 symptom, but a different root cause there
(`ContextID ... should have been in the ID-to-project file mapping but wasn't!`).

### Workaround

Drop `-check` from the build.

Contributor guide

No contributing guide indexed for this repository

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.