dotnet / dotnet/msbuild

[Performance]: `GetTargetPathWithTargetPlatformMoniker` and `GetTargetPath` target post-processing can take multiple minutes on large projects.

Open
#8,985 16 comments 0 reactions 0 assignees View on GitHub
Area: Engine Area: Performance backlog Priority:2 triaged
Dominant language
C#
Stars
5.5k
Forks
1.5k
Avg merge
1d 13h
Merged PRs (30d)
133

Description

### Issue Description

On large highly interdependent projects the `GetTargetPathWithTargetPlatformMoniker` and `GetTargetPath` targets (from Microsoft.Common.CurrentVersion.targets) can end up taking multiple minutes to run. `GetTargetPathWithTargetPlatformMonike` doesn't do anything expensive, it just creates a new project Item with some metadata, but it has a `Returns` attrribute that returns `@(TargetPathWithTargetPlatformMoniker)` which due to post processing in MSBuild to handle the returns, can take a long time to execute. Since the `GetTargetPath` target is essentially a passthrough for this value, it takes almost the exact same amount of time. For our large project we have seen each of these targets take upwards of 3.5 minutes to run.

The behavior can be seen to a lesser effect on other projects in the solution where each target takes ~20 second or ~1 minute to run.

Overall build time:
![image](https://github.com/dotnet/msbuild/assets/1055021/f1b2a9dd-3e91-4b47-8fdb-00de37e53507)

Time spent on the two targets (note: these targets are serial, not parallel, so it is almost minutes in total)
![image](https://github.com/dotnet/msbuild/assets/1055021/b7c2b22e-cd77-4bf7-9820-21c90c53da72)

### Steps to Reproduce

I'm happy to privately share a binlog of the build, but the descript here should be enough to identify the source of the problem.

### Data

Call stack during 3minute hangs:

```
System.Collections.Immutable.dll!System.Collections.Immutable.SortedInt32KeyNode`1.Freeze+0x1a
System.Collections.Immutable.dll!System.Collections.Immutable.SortedInt32KeyNode`1.Freeze+0xbb
System.Collections.Immutable.dll!System.Collections.Immutable.SortedInt32KeyNode`1.Freeze+0xc9
System.Collections.Immutable.dll!System.Collections.Immutable.SortedInt32KeyNode`1.Freeze+0xc9
System.Collections.Immutable.dll!System.Collections.Immutable.ImmutableDictionary`2..ctor+0x7f
System.Collections.Immutable.dll!System.Collections.Immutable.ImmutableDictionary`2.Wrap+0x5d
System.Collections.Immutable.dll!System.Collections.Immutable.ImmutableDictionary`2.SetItem+0xb3
Microsoft.Build.dll!Microsoft.Build.Collections.CopyOnWritePropertyDictionary`1.Set+0x58
Microsoft.Build.dll!TaskItem.get_MetadataCollection+0x242
Microsoft.Build.dll!TaskItem.Equals+0x263
mscorlib.dll!System.Collections.Generic.GenericEqualityComparer`1.Equals+0x56
System.Core.dll!System.Collections.Generic.HashSet`1.Contains+0xda
Microsoft.Build.dll!d__44.MoveNext+0xd3f
mscorlib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start+0x80
Microsoft.Build.dll!Microsoft.Build.BackEnd.TargetEntry.ExecuteTarget+0x79
Microsoft.Build.dll!d__23.MoveNext+0x911
mscorlib.dll!System.Threading.ExecutionContext.RunInternal+0x172
mscorlib.dll!System.Threading.ExecutionContext.Run+0x15
mscorlib.dll!MoveNextRunner.Run+0x6f
mscorlib.dll!<>c.b__2_0+0x36
mscorlib.dll!System.Threading.Tasks.Task.Execute+0x47
mscorlib.dll!System.Threading.Tasks.Task.ExecuteWithThreadLocal+0x18c
mscorlib.dll!System.Threading.Tasks.Task.ExecuteEntry+0xa1
Microsoft.Build.dll!DedicatedThreadsTaskScheduler.b__6_0+0x78
mscorlib.dll!System.Threading.ExecutionContext.RunInternal+0x172
mscorlib.dll!System.Threading.ExecutionContext.Run+0x15
mscorlib.dll!System.Threading.ExecutionContext.Run+0x55
mscorlib.dll!System.Threading.ThreadHelper.ThreadStart+0x55
[Unmanaged to Managed Transition]
clr.dll!DllCanUnloadNowInternal+0x10f3
clr.dll!DllCanUnloadNowInternal+0x1000
clr.dll!DllCanUnloadNowInternal+0x18b0
clr.dll!MetaDataGetDispenser+0xcdaf
clr.dll!DllCanUnloadNowInternal+0x2498
clr.dll!DllCanUnloadNowInternal+0x2403
clr.dll!DllCanUnloadNowInternal+0x2342
clr.dll!DllCanUnloadNowInternal+0x2533
clr.dll!MetaDataGetDispenser+0xcc99
clr.dll!DllCanUnloadNowInternal+0x6015
KERNEL32.dll!BaseThreadInitThunk+0x14
ntdll.dll!RtlUserThreadStart+0x21

```

### Analysis

Example project structure:
* Service.Stuff.csproj
* Service.Core.csproj
* Service.Interfaces.csproj
* Common.csproj
* Service.Interfaces.csproj
* Common.csproj
* Common.csproj

`GetTargetPath` gets called on each of these, and because of the metadata introduced at different levels, it produces 7 different `TargetPathWithTargetPlatformMoniker` items. For Common.csproj, these items all have the same `ItemSpec` (essentially just `"Common.csproj"`) but they differ in their metadata.

This example has 7 items. In our solution with 385 projects we have a PostBuild project that references every other project. When this runs, the `@(TargetPathWithTargetPlatformMoniker)` collection has ~50K items.

As part of the post-processing for the target, since they have a `Returns` attribute, there is [some work done to dedupe this collection](https://github.com/dotnet/msbuild/blob/main/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs#L604-L647). It uses a `HashSet` to do the deduping. However, [the hashcode for the TaskItem only takes into account the ItemSpec](https://github.com/dotnet/msbuild/blob/main/src/Build/Instance/ProjectItemInstance.cs#L1498) so there ends up being a lot of hash collisions and it falls back to doing an expensive comparison which [generates and compares the entire metadata collection of the item](https://github.com/dotnet/msbuild/blob/main/src/Build/Instance/ProjectItemInstance.cs#L1519).

Our PostBuild project is the most extreme example of this, but you can see that this problem appears even in projects that are significantly smaller, but this step still ends up taking an excessively long time (we have multiple projects that take >10s for each of these targets and it compounds over all the projects).

### Versions & Configurations

We are using MSBuild 17.2.0, but i've analyzed the call paths and I don't see any changes between that version and the most recent build that would change this behavior.

```
Microsoft (R) Build Engine version 17.2.1+52cd2da31 for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.

17.2.1.25201
```

### Regression

- [X] yes
- [ ] no

### Regression Details

We have been using this common PostBuild project for years, but apparently the slowdowns have only really started as part of modernizing to newer versions of MSBuild and .NET.

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.