dotnet build is slow for simple projects

[agocke]

When talking with a customer, they mentioned that they tried C# but weren't interested in continuing because it took >2 seconds to build "hello world."

On my machine:

$ time dotnet build -t:rebuild

real    0m1.752s
user    0m2.240s
sys     0m0.229s

Some other languages:

Go

$ time go build main.go

real    0m0.137s
user    0m0.140s
sys     0m0.056s

Rust

$ time cargo build
   Compiling hello_cargo v0.1.0 (/home/andy/tmp/hellogo/cargo/hello_cargo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.34s

real    0m0.376s
user    0m0.255s
sys     0m0.056s

Maven

$ time mvn compile -q

real    0m0.985s
user    0m3.108s
sys     0m0.382s

Java directly

andy@angocke-dev3  ~/tmp/hellogo/java/my-app/src/main/java/com/mycompany/app
$ time javac App.java

real    0m0.331s
user    0m0.837s
sys     0m0.058s

[marcpopMSFT]

There was a push for inner loop performance back in .NET 6 but generally there was not a lot of low hanging fruit found to improve the simple CLI. Some small improvements were made but then the effort was moved on from . CC @brianrob who drove that effort.

[bolner]

This is especially annoying while iterating debugging over a unit test. After clicking on "Debug Test" (VS Code with the basic C# extension), it takes like 5-6 seconds to get to the breakpoint (no I/O involved) in a small project.

[dgilleland]

I am also seeing quite slow performance in .NET 8 on a build of fairly simple code. I'm teaching introductory C# at the post-secondary level, so we're not talking rocket science here.

Here's the perf stats on a small solution with three projects: classlib, console, and xunit

The short summary is seen in these few lines (truncated to show only the long-running parts):

dotnet build --no-restore /clp:PerformanceSummary
MSBuild version 17.8.3+195e7f5a3 for .NET

Project Evaluation Performance Summary:
       42 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedClasses.sln.metaproj   1 calls
       53 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\DemoClasses\DemoClasses.csproj   1 calls
       56 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos.Specs\AssortedDemos.Specs.csproj   1 calls
      151 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj   1 calls

Project Performance Summary:
     1983 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj  10 calls
                  2 ms  GetTargetFrameworks                        2 calls
                  0 ms  GetNativeManifest                          2 calls
                  0 ms  InitializeSourceRootMappedPaths            1 calls
                  0 ms  GetCopyToOutputDirectoryItems              2 calls
     2670 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos.Specs\AssortedDemos.Specs.csproj   1 calls
    12794 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\DemoClasses\DemoClasses.csproj   1 calls
    12921 ms  C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedClasses.sln   1 calls

Target Performance Summary:  # truncated results
       85 ms  InitializeSourceControlInformationFromSourceControlManager   3 calls
       93 ms  ResolveAssemblyReferences                  3 calls
      104 ms  CopyFilesToOutputDirectory                 3 calls
     2201 ms  CoreCompile                                3 calls
     4087 ms  _GetProjectReferenceTargetFrameworkProperties   3 calls
    10108 ms  _CreateAppHost                             1 calls
    12907 ms  Build                                      4 calls

Task Performance Summary:  # truncated results
      120 ms  WriteLinesToFile                          12 calls
     2195 ms  Csc                                        3 calls
    10108 ms  CreateAppHost                              1 calls
    16937 ms  MSBuild                                   11 calls

Build succeeded.

---

Here's the full details of the build with the performance summary:

dotnet build --no-restore /clp:PerformanceSummary

MSBuild version 17.8.3+195e7f5a3 for .NET C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Person.cs(43,12): warning CS8618: Non-nullable field '_FirstName' must contain a non-null value when exiting constructor. Consider declaring the field as nullable. [C:\GH\2 024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj] C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Person.cs(43,12): warning CS8618: Non-nullable field '_LastName' must contain a non-null value when exiting constructor. Consider declaring the field as nullable. [C:\GH\20 24-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj] C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\PhoneBook.cs(24,29): warning CS8600: Converting null literal or possible null value to non-nullable type. [C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos \Assorted.csproj] C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\PhoneBook.cs(28,16): warning CS8603: Possible null re ference return. [C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj] C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Fraction.cs(42,22): warning CS8625: Cannot convert nu ll literal to non-nullable reference type. [C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted. csproj] Assorted -> C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\bin\Debug\net8.0\Assorted.dll AssortedDemos.Specs -> C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos.Specs\bin\Debug\net8.0\Assor tedDemos.Specs.dll DemoClasses -> C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\DemoClasses\bin\Debug\net8.0\DemoClasses.dll

Project Evaluation Performance Summary:
42 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedClasses.sln.metaproj 1 calls
53 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\DemoClasses\DemoClasses.csproj 1 calls
56 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos.Specs\AssortedDemos.Specs.csproj 1 calls
151 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj 1 calls

Project Performance Summary:
1983 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos\Assorted.csproj 10 calls
2 ms GetTargetFrameworks 2 calls
0 ms GetNativeManifest 2 calls
0 ms InitializeSourceRootMappedPaths 1 calls
0 ms GetCopyToOutputDirectoryItems 2 calls
2670 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedDemos.Specs\AssortedDemos.Specs.csproj 1 calls
12794 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\DemoClasses\DemoClasses.csproj 1 calls
12921 ms C:\GH\2024-Jan-In-Class\1517-A02-Instructor\src\005\AssortedClasses.sln 1 calls

Target Performance Summary:
0 ms InitializeSourceControlInformation 3 calls
0 ms PrepareResourceNames 3 calls
0 ms BeforeCompile 3 calls
0 ms ResGen 3 calls
0 ms ValidateProjects 1 calls
0 ms BeforeResGen 3 calls
0 ms PrepareResources 3 calls
0 ms _ChooseAppHost 1 calls
0 ms _InitializeSourceRootMappedPathsFromSourceControl 3 calls
0 ms _InitializeSourceControlInformationFromSourceControlManager 3 calls
0 ms PrepareProjectReferences 3 calls
0 ms BeforeBuild 3 calls
0 ms SetWin32ManifestProperties 3 calls
0 ms Compile 3 calls
0 ms ResolvePackageDependenciesForBuild 3 calls
0 ms GetReferenceAssemblyPaths 3 calls
0 ms GenerateMSBuildEditorConfigFile 3 calls
0 ms AfterResGen 3 calls
0 ms CreateSatelliteAssemblies 3 calls
0 ms GetFrameworkPaths 3 calls
0 ms _CopySourceItemsToOutputDirectory 3 calls
0 ms CreateCustomManifestResourceNames 3 calls
0 ms ValidateCommandLineProperties 3 calls
0 ms _InitializeSourceRootMappedPathsOpt 3 calls
0 ms AfterResolveReferences 3 calls
0 ms AfterBuild 3 calls
0 ms AfterCompile 3 calls
0 ms GenerateAssemblyInfo 3 calls
0 ms CoreBuild 3 calls
0 ms PrepareForRun 3 calls
0 ms _SetEmbeddedFilesFromSourceControlManagerUntrackedFiles 3 calls
0 ms BeforeResolveReferences 3 calls
0 ms GetTargetPath 3 calls
0 ms GenerateSourceLinkFile 3 calls
0 ms BuildOnlySettings 3 calls
0 ms ValidateToolsVersions 1 calls
0 ms _SetTargetFrameworkMonikerAttribute 3 calls
0 ms _AddOutputPathToGlobalPropertiesToRemove 3 calls
0 ms IncludeTransitiveProjectReferences 3 calls
0 ms EnableIntermediateOutputPathMismatchWarning 3 calls
0 ms _CheckForUnsupportedHostingUsage 3 calls
0 ms _PopulateCommonStateForGetCopyToOutputDirectoryItems 3 calls
0 ms _DefaultMicrosoftNETPlatformLibrary 3 calls
0 ms ResolveLockFileAnalyzers 3 calls
0 ms CopyAdditionalFiles 3 calls
0 ms _GetAppHostPaths 1 calls
0 ms _ComputeNETCoreBuildOutputFiles 3 calls
0 ms _SetSourceLinkFilePath 3 calls
0 ms _CheckAndUnsetUnsupportedPrefer32Bit 3 calls
0 ms ResolveSDKReferences 3 calls
0 ms ExpandSDKReferences 3 calls
0 ms _ReportUpgradeNetAnalyzersNuGetWarning 3 calls
0 ms _CheckForUnsupportedCppNETCoreVersion 3 calls
0 ms AddSourceRevisionToInformationalVersion 3 calls
0 ms _BeforeVBCSCoreCompile 3 calls
0 ms _CheckForUnsupportedArtifactsPath 3 calls
0 ms AddImplicitDefineConstants 3 calls
0 ms _CheckForLanguageAndFeatureCombinationSupport 3 calls
0 ms _GetProjectJsonPath 3 calls
0 ms GenerateMSBuildEditorConfigFileShouldRun 3 calls
0 ms IgnoreJavaScriptOutputAssembly 3 calls
0 ms _CheckForObsoleteDotNetCliToolReferences 3 calls
0 ms ResolveReferences 3 calls
0 ms GetNativeManifest 1 calls
0 ms AddDepsJsonAndRuntimeConfigToCopyItemsForReferencingProjects 2 calls
0 ms SourceControlManagerPublishTranslatedUrls 3 calls
0 ms _ComputePackageReferencePublish 3 calls
0 ms GetTargetPathWithTargetPlatformMoniker 3 calls
0 ms _AddMicrosoftNetCompilerToolsetFrameworkPackage 3 calls
0 ms _CheckForUnsupportedNETCoreVersion 3 calls
0 ms _GenerateCompileInputs 3 calls
0 ms GetAssemblyAttributes 3 calls
0 ms ApplyImplicitVersions 1 calls
1 ms GenerateProgramFile 1 calls
1 ms _ComputeSkipAnalyzers 3 calls
1 ms CoreResGen 3 calls
1 ms GetTargetFrameworks 1 calls
1 ms _CheckForUnsupportedAppHostUsage 2 calls
1 ms _GenerateSatelliteAssemblyInputs 3 calls
1 ms GetAssemblyVersion 3 calls
1 ms UpdateAspNetToFrameworkReference 1 calls
1 ms GetTargetFrameworksWithPlatformForSingleTargetFramework 1 calls
1 ms _SplitProjectReferencesByFileExistence 3 calls
1 ms _BlockWinMDsOnUnsupportedTFMs 3 calls
1 ms ResolveLockFileCopyLocalFiles 3 calls
1 ms ValidateExecutableReferences 2 calls
1 ms _GetCopyToOutputDirectoryItemsFromThisProject 3 calls
2 ms SplitResourcesByCulture 3 calls
2 ms GenerateTargetFrameworkMonikerAttribute 3 calls
2 ms CheckForImplicitPackageReferenceOverrides 3 calls
2 ms _CheckForCompileOutputs 3 calls
2 ms GenerateBuildRuntimeConfigurationFiles 2 calls
2 ms InitializeSourceRootMappedPaths 3 calls
3 ms _ComputeReferenceAssemblies 3 calls
3 ms _ComputeUserRuntimeAssemblies 3 calls
3 ms CheckForDuplicateItems 3 calls
3 ms _CheckForInvalidConfigurationAndPlatform 3 calls
3 ms ResolveLockFileReferences 3 calls
3 ms AddGlobalAnalyzerConfigForPackage_MicrosoftCodeAnalysisNetAnalyzers 3 calls
3 ms AssignTargetPaths 3 calls
3 ms ResolveOffByDefaultAnalyzers 3 calls
3 ms _SetEmbeddedWin32ManifestProperties 3 calls
4 ms IncrementalClean 3 calls
4 ms _GetRestoreProjectStyle 3 calls
4 ms GenerateNETCompatibleDefineConstants 3 calls
4 ms _ComputeToolPackInputsToProcessFrameworkReferences 3 calls
4 ms GenerateBuildDependencyFile 3 calls
5 ms AssignProjectConfiguration 3 calls
5 ms ReferencedPathMaps 1 calls
5 ms _SourceLinkHasSingleProvider 3 calls
6 ms _InitializeBitbucketGitSourceLinkUrl 6 calls
6 ms GenerateMSBuildEditorConfigFileCore 3 calls
7 ms _GetCopyToOutputDirectoryItemsFromTransitiveProjectReferences 3 calls
7 ms _InitializeGitLabSourceLinkUrl 6 calls
7 ms CreateGeneratedAssemblyInfoInputsCacheFile 3 calls
7 ms _InitializeAzureReposGitSourceLinkUrl 6 calls
8 ms PrepareForBuild 3 calls
8 ms ResolveFrameworkReferences 3 calls
9 ms _CollectTargetFrameworkForTelemetry 3 calls
10 ms GenerateGlobalUsings 3 calls
10 ms ValidateSolutionConfiguration 1 calls
10 ms _CopyOutOfDateSourceItemsToOutputDirectory 2 calls
10 ms ResolveProjectReferences 3 calls
10 ms TranslateGitLabUrlsInSourceControlInformation 3 calls
11 ms TranslateBitbucketGitUrlsInSourceControlInformation 3 calls
11 ms TranslateGitHubUrlsInSourceControlInformation 3 calls
12 ms CollectPackageReferences 3 calls
12 ms TranslateAzureReposGitUrlsInSourceControlInformation 3 calls
12 ms ResolvePackageAssets 3 calls
17 ms GetCopyToOutputDirectoryItems 3 calls
18 ms _InitializeGitHubSourceLinkUrl 6 calls
20 ms ResolveTargetingPackAssets 3 calls
31 ms _HandlePackageFileConflicts 3 calls
34 ms FindReferenceAssembliesForReferences 3 calls
36 ms CoreGenerateAssemblyInfo 3 calls
38 ms _GenerateSourceLinkFile 3 calls
42 ms _GenerateRuntimeConfigurationFilesInputCache 2 calls
42 ms _CopyFilesMarkedCopyLocal 2 calls
49 ms _CleanGetCurrentAndPriorFileWrites 3 calls
52 ms SetEmbeddedFilesFromSourceControlManagerUntrackedFiles 3 calls
54 ms ProcessFrameworkReferences 3 calls
70 ms _GenerateCompileDependencyCache 3 calls
85 ms InitializeSourceControlInformationFromSourceControlManager 3 calls
93 ms ResolveAssemblyReferences 3 calls
104 ms CopyFilesToOutputDirectory 3 calls
2201 ms CoreCompile 3 calls
4087 ms _GetProjectReferenceTargetFrameworkProperties 3 calls
10108 ms _CreateAppHost 1 calls
12907 ms Build 4 calls

Task Performance Summary:
0 ms ApplyImplicitVersions 1 calls
0 ms CombineXmlElements 1 calls
0 ms AssignCulture 3 calls
0 ms GetAssemblyVersion 3 calls
0 ms CombineTargetFrameworkInfoProperties 1 calls
0 ms CheckForUnsupportedWinMDReferences 3 calls
1 ms Delete 3 calls
1 ms CheckIfPackageReferenceShouldBeFrameworkReference 2 calls
1 ms ResolveFrameworkReferences 3 calls
1 ms SetRidAgnosticValueForProjects 3 calls
1 ms CheckForDuplicateFrameworkReferences 3 calls
1 ms ValidateExecutableReferences 2 calls
1 ms FindAppConfigFile 3 calls
1 ms Microsoft.SourceLink.Common.SourceLinkHasSingleProvider 3 calls
1 ms ConvertToAbsolutePath 3 calls
1 ms CheckForImplicitPackageReferenceOverrides 3 calls
1 ms Microsoft.CodeAnalysis.BuildTasks.MapSourceRoots 3 calls
1 ms JoinItems 3 calls
1 ms CheckForDuplicateNuGetItemsTask 3 calls
1 ms RemoveDuplicates 6 calls
2 ms AllowEmptyTelemetry 3 calls
2 ms GenerateMSBuildEditorConfig 3 calls
2 ms CheckForDuplicateItems 9 calls
2 ms GetFrameworkPath 3 calls
2 ms AssignTargetPath 18 calls
3 ms Hash 8 calls
3 ms GetRestoreProjectStyleTask 3 calls
3 ms AssignProjectConfiguration 3 calls
4 ms Message 10 calls
4 ms Touch 2 calls
4 ms GenerateGlobalUsings 3 calls
5 ms Microsoft.SourceLink.Bitbucket.Git.GetSourceLinkUrl 6 calls
5 ms GetPackageDirectory 30 calls
5 ms Microsoft.SourceLink.GitLab.GetSourceLinkUrl 6 calls
6 ms Microsoft.SourceLink.AzureRepos.Git.GetSourceLinkUrl 6 calls
6 ms Microsoft.SourceLink.GitLab.TranslateRepositoryUrls 3 calls
6 ms MakeDir 3 calls
6 ms FindUnderPath 15 calls
6 ms Microsoft.SourceLink.Bitbucket.Git.TranslateRepositoryUrls 3 calls
7 ms Microsoft.SourceLink.GitHub.TranslateRepositoryUrls 3 calls
7 ms Microsoft.SourceLink.AzureRepos.Git.TranslateRepositoryUrls 3 calls
10 ms ResolvePackageAssets 3 calls
14 ms CallTarget 6 calls
17 ms Microsoft.SourceLink.GitHub.GetSourceLinkUrl 6 calls
18 ms ResolveAppHosts 3 calls
19 ms ResolveTargetingPackAssets 3 calls
28 ms ResolvePackageFileConflicts 3 calls
31 ms GetReferenceNearestTargetFrameworkTask 2 calls
31 ms ProcessFrameworkReferences 3 calls
34 ms WriteCodeFragment 3 calls
35 ms ReadLinesFromFile 3 calls
37 ms Microsoft.SourceLink.Common.GenerateSourceLinkFile 3 calls
51 ms Microsoft.Build.Tasks.Git.GetUntrackedFiles 3 calls
67 ms Copy 9 calls
76 ms CopyRefAssembly 3 calls
82 ms Microsoft.Build.Tasks.Git.LocateRepository 3 calls
91 ms ResolveAssemblyReference 3 calls
120 ms WriteLinesToFile 12 calls
2195 ms Csc 3 calls
10108 ms CreateAppHost 1 calls
16937 ms MSBuild 11 calls

Build succeeded.


And here's my SDK installation (the machine is pretty clean & new - fresh since Sep 2023):

dotnet sdk check

.NET SDKs: Version Status --------------------------------------------------- 7.0.403 .NET 7.0 is going out of support soon. 8.0.100 Patch 8.0.101 is available.

Try out the newest .NET SDK features with .NET 8.0.101.

.NET Runtimes:
Name Version Status

Microsoft.NETCore.App 6.0.9 Patch 6.0.26 is available.
Microsoft.WindowsDesktop.App 6.0.9 Patch 6.0.26 is available.
Microsoft.NETCore.App 6.0.20 Patch 6.0.26 is available.
Microsoft.AspNetCore.App 7.0.13 .NET 7.0 is going out of support soon.
Microsoft.NETCore.App 7.0.13 .NET 7.0 is going out of support soon.
Microsoft.WindowsDesktop.App 7.0.13 .NET 7.0 is going out of support soon.
Microsoft.AspNetCore.App 8.0.0 Patch 8.0.1 is available.
Microsoft.NETCore.App 8.0.0 Patch 8.0.1 is available.
Microsoft.WindowsDesktop.App 8.0.0 Patch 8.0.1 is available.


[dgilleland]

Also, does this issue need the Area-CLI tag, or the cli-ux tag?

[baronfel]

@dgilleland we'd need to see an https://aka.ms/binlog to get a real sense of what's going on here - these can contain sensitive data, so if you would like to submit one I would recommend opening a ticket at VS Developer Community and uploading it there as a private asset, then linking to that ticket here.

As a reference point, I cloned down your repo and built it in 6.7 seconds, with 2.5 of that being Restore, and the remainder being actually building (at 3.5s). Most of the build time is doing TargetFramework negotiation between the projects that reference Assorted.csproj, (which happens multiple times), so there's potentially something we could look into there. But nothing on my end suggests something going terribly bad, which is why we need a binlog to see what's up on your machine.

The Area-CLI and related tags are mostly around the CLI arguments/commands/options and help display, not so much the perf of a build, which is mostly controlled by the behavior of the tasks and targets in the .NET SDK.

[dgilleland]

@baronfel - Thanks for that analysis! That link for bin logs is very helpful to know!

I don't think I'll open a ticket as it's not really a big issue for me at present, and it could easily be due to something that I did to my machine. I thought that I would post my experience in the hope that it would help reveal a clue for others who are having this issue. Learning how to properly gather/supply useful info when posting issues is a good skill.

Tip for others: log/debug info can be pretty long to look at in GitHub issues, so it can be helpful at times to wrap them in a <details> tag to cut down on the noise for people who are just searching to see if it applies to them (while making it helpful for those, like @baronfel, who put in their expertise in analyzing the logs).

<details>
  <summary>description</summary>
lotsa-lines-of-logs
</details>

Thanks again! I learned something today !

[NinekoTheCat]

This is still relevant, just commenting so it doesn't get buried. You can do better and should strive to, especially if you want us to build complex projects!