Performance issues

[AlexanderRydberg]

Last week, we received a batch of new machines that we integrated into our build pipeline. To my surprise, these new machines turned out to be slower than my older ones. This prompted me to initiate an investigation into the matter.

Here's a comparison of the specifications for the machines in question:

Spec	Machine A	Machine B	Machine C
OS	Windows Server 2019	Windows 11 Pro	Windows Server 2019
CPU	Intel Core i7-8700 (Gen 8)	Intel Core I7-12700 (Gen 12)	Intel Core I7-12700 (Gen 12)
RAM	4gb x 4 @ 2666mhz	8gb x 2 @ 3200mhz	8gb x 2 @ 3200mhz
HDD	KXG60ZNV512G	MTFDHBA512QFD	MTFDHBA512QFD

Machine B and Machine C have identical hardware and bios configuration. Based on the specifications, the 12th Gen CPU should outperform the 8th Gen CPU. Performance tests were conducted to further investigate this.

Performance comparison using Cinebench scores:

Specification	Machine A	Machine B	Machine C
Multi-Core pts	445	801	892
Single-Core pts	72	111	731

Additionally, Atto Disk Benchmark results indicate that Machine B's drive performs better in both byte/s and I/O's read/write.

Everything points to Machine B/C being the better machine...

MSBuild Versions:

Machine A	Machine B & Machine C
17.5.1+f6fdcf537 for .NET Framework	17.7.2+d6990bcfa for .NET Framework

Build Time Elapsed

• These args never change -t:Restore;Rebuild -p:Configuration=Release
• Builds are executed using TeamCity, with each build run twice on each machine. The time taken for the second build is recorded.
  This is what TC executes (custom args here are /ds /v:diag) ):

Starting: "C:\Program Files (x86)\Microsoft Visual Studio\2022\BuildTools\MSBuild\Current\Bin\MSBuild.exe" C:\BuildAgent\work\1271ea4d82d8eec7\xxx\xxx\xxx.Service\xxx.Service.csproj -t:Restore;Rebuild -p:Configuration=Release @C:\BuildAgent\temp\agentTmp\1.rsp /ds /v:diag
in directory: C:\BuildAgent\work\1271ea4d82d8eec7
MSBuild version 17.7.2+d6990bcfa for .NET Framework
C:\Program Files (x86)\Microsoft Visual Studio\2022\BuildTools\MSBuild\Current\Bin\MSBuild.exe /noconsolelogger -p:Configuration=Release -p:VSTestLogger=teamcity -p:VSTestTestAdapterPath=C:\BuildAgent\work\1271ea4d82d8eec7 -p:VSTestVerbosity=normal -p:agent_home_dir=C:\BuildAgent -p:agent_name=MachineC -p:agent_work_dir=C:\BuildAgent\work -p:build_number=6badebb -p:build_vcs_number=xxx -p:build_vcs_number_1=xxx -p:build_vcs_number_xxx_github=xxx -p:java_io_tmpdir=C:\BuildAgent\temp\buildTmp -p:teamcity_agent_cpuBenchmark=1032 -p:teamcity_agent_dotnet_agent_url=xxx -p:teamcity_agent_dotnet_build_id=3146525 -p:teamcity_auth_password=xxx -p:teamcity_auth_userId=xxx -p:teamcity_build_changedFiles_file=C:\BuildAgent\temp\buildTmp\teamcity.changedFiles.txt -p:teamcity_build_checkoutDir=C:\BuildAgent\work\1271ea4d82d8eec7 -p:teamcity_build_properties_file=C:\BuildAgent\temp\buildTmp\teamcity.build.parameters -p:teamcity_build_tempDir=C:\BuildAgent\temp\buildTmp -p:teamcity_build_workingDir=C:\BuildAgent\work\1271ea4d82d8eec7 -p:teamcity_buildConfName=TimeTest -p:teamcity_buildType_id=xxx_TimeTest -p:teamcity_configuration_properties_file=C:\BuildAgent\temp\buildTmp\teamcity.config.parameters -p:teamcity_dotnet_nunitaddin=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.TeamCity.NUnitAddin-NUnit -p:teamcity_dotnet_nunitlauncher=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher.exe -p:teamcity_dotnet_nunitlauncher_msbuild_task=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.MSBuildLoggers.dll -p:teamcity_dotnet_nunitlauncher1_1=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher1.1.exe -p:teamcity_dotnet_nunitlauncher2_0=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher2.0.exe -p:teamcity_dotnet_nunitlauncher2_0_vsts=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher2.0.VSTS.exe -p:teamcity_dotnet_platform=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.TeamCity.PlatformProcessRunner.1.1.exe -p:teamcity_nuget_feed__Root_TCFeed_publicUrl=xxx -p:teamcity_nuget_feed__Root_TCFeed_url=xxx -p:teamcity_projectName=xxx -p:teamcity_runner_properties_file=C:\BuildAgent\temp\buildTmp\teamcity.runner.parameters -p:teamcity_tests_recentlyFailedTests_file=C:\BuildAgent\temp\buildTmp\teamcity.testsToRunFirst.txt -p:teamcity_version=2023.05.4 (build 129421) -t:Restore;Rebuild /ds /l:TeamCity.MSBuild.Logger.TeamCityMSBuildLogger,C:\BuildAgent\plugins\dotnet\tools\msbuild15\TeamCity.MSBuild.Logger.dll;TeamCity;plain /v:diag C:\BuildAgent\work\1271ea4d82d8eec7\xxx\xxx\xxx.Service\xxx.Service.csproj
Logger parameters: Debug: False, ShowOnlyWarnings: False, ShowEnvironment: False, Verbosity: Diagnostic, ShowPerfSummary: True, ShowItemAndPropertyList: False, ShowSummary: True, ShowOnlyErrors: False, ShowProjectFile: False, ShowCommandLine: , ShowTimeStamp: False, ShowEventId: , ForceNoAlign: True, AlignMessages: False, ShowTargetOutputs: False, BufferWidth: -1, ColorMode: TeamCity, TeamCityMode: SupportHierarchy, StatisticsMode: TeamCity, ColorThemeMode: TeamCity, PlainServiceMessage: True

Build Time Elapsed Results

MSBuild Args	Machine A	Machine B	Machine C
/ds	01:19.22	01:30.99	01:22.37
/ds /m:2	01:01.47	01:16.13	00:55.20
/ds /m:4	00:51.40	01:00.95	00:46.28
/ds /m:8	00:49.65	00:59.84	00:39.17
/ds /m:12	00:49.36	00:57.62	00:39.94
/ds /m	00:48.60	00:59.28	00:42.81
/ds /v:diag	05:24.09	04:20.82	05:58.37
/ds /m /v:diag	04:02.36	02:42.44	04:14.05
/ds /m:12 /v:diag	04:02.24	02:42.73	03:29.89

I have some questions based on these results

• Do the results make sense, and if so, why?
• Which operating system is best for MSBuild?
• Does MSBuild treat all cores equally? Meaning, it doesnt care if its a p-core or e-core?
• How can we improve MSBuild's performance?

Footnotes

1. Here I suspect that cinebench ran on e-core. Did a second run where I changed affinity to only p-cores, and got a score of 111. ↩

[rainersigwald]

Do you have the same antivirus configuration across machines? That can be a dominant factor in these types of measurement.

• Do the results make sense, and if so, why?

Maybe in some cases, but something does seem off.

If you're not specifying -m, then having more cores won't matter to MSBuild (it can still improve compiler and other tool performance depending on their own internal parallelizability). Same for ones where you specify a low core count like 2 or 4: the new processors aren't that much faster per core, so similar results across machines is expected.

• Which operating system is best for MSBuild?

It shouldn't matter much! We don't do anything specific on Server or to use new APIs for Win11.

• Does MSBuild treat all cores equally? Meaning, it doesnt care if its a p-core or e-core?

Yes, because we don't know of a good way to do otherwise. For the most part we consider it a win if we can saturate all processors.

• How can we improve MSBuild's performance?

The generalities here are "watch your critical path" and "parallelize as much as possible" (and "make incremental work correctly" but that doesn't apply here). If you capture a binlog, and are willing to share it (note the details that are shared in the log and make sure you're comfortable with that!) we might be able to look over it and see if anything jumps out (and write down what we're doing for posterity).

[AlexanderRydberg]

Feel free to request a feature, though I'll want to hear why you're interested in the limit

I remember reading somewhere that it's recommended to set it to 'max - 2,' but I can't seem to locate that source now. If I gather enough data in the future that points to that being beneficial, I might try my luck with a PR.

Anything jump out in a diff of the details of the RAR execution?

Cant really see any major difference. Generally all of those tasks takes alot longer time. But I dont really know what to look for. Any tips on what to look for?

I've experimented extensively with Machine B, and I've developed a theory (it feels like I've gone through quite a few theories). I suspect that Windows 11 may be the culprit, and I believe I have data that supports this hypothesis.

Fresh Windows 11 22621.1702. Should also add that no drivers are manually added.
KB5032381 and KB5031274 was added right after reinstall.
Ran about 20 builds and all of them were in the same ballpark of time

Top 10 most expensive tasks
    Csc = 54.762 s, 91 calls.
        CoreCompile = 54.762 s, 91 calls.
    ResolveAssemblyReference = 13.005 s, 91 calls.
        ResolveAssemblyReferences = 13.005 s, 91 calls.
    Copy = 3.112 s, 324 calls.
        _CopyFilesMarkedCopyLocal = 2.821 s, 85 calls.
        CopyFilesToOutputDirectory = 247 ms, 203 calls.
        _CopyOutOfDateSourceItemsToOutputDirectory = 24 ms, 19 calls.
        _CopyAppConfigFile = 19 ms, 17 calls.
    AL = 2.295 s, 41 calls.
        GenerateSatelliteAssemblies = 2.295 s, 41 calls.
    Exec = 2.107 s, 27 calls.
        PreBuild = 1.138 s, 15 calls.
        PreBuildEvent = 947 ms, 11 calls.
        PostBuildEvent = 21 ms, 1 calls.
    RestoreTask = 1.193 s, 1 calls.
        Restore = 1.193 s, 1 calls.
    GenerateResource = 737 ms, 22 calls.
        CoreResGen = 737 ms, 22 calls.
    GetRestoreSettingsTask = 605 ms, 91 calls.
        _GetRestoreSettings = 605 ms, 91 calls.
    ResolvePackageFileConflicts = 472 ms, 91 calls.
        _HandlePackageFileConflicts = 472 ms, 91 calls.
    ResolvePackageAssets = 459 ms, 35 calls.
        ResolvePackageAssets = 459 ms, 35 calls.

Okay results. But ResolveAssemblyReferences still stands out.

Running Windows Update: KB5031354, KB5031455, KB5031323, KB2267602, KB5031323, KB890830, KB5007651, KB4023057, Realtek Semiconductor Corp. - USB - 10.0.22621.31276, Intel - Net - 12.19.2.45, INTEL - System - 10.1.45.9
These failed: KB5031354, KB5031455, KB5031323
Build result after reboot.

Top 10 most expensive tasks
    Csc = 7:04.626, 91 calls.
        CoreCompile = 7:04.626, 91 calls.
    ResolveAssemblyReference = 42.589 s, 91 calls.
        ResolveAssemblyReferences = 42.589 s, 91 calls.
    Exec = 7.612 s, 27 calls.
        PreBuild = 5.573 s, 15 calls.
        PreBuildEvent = 2.014 s, 11 calls.
        PostBuildEvent = 24 ms, 1 calls.
    Copy = 4.756 s, 324 calls.
        _CopyFilesMarkedCopyLocal = 4.426 s, 85 calls.
        CopyFilesToOutputDirectory = 291 ms, 203 calls.
        _CopyOutOfDateSourceItemsToOutputDirectory = 25 ms, 19 calls.
        _CopyAppConfigFile = 12 ms, 17 calls.
    GetRestoreSettingsTask = 3.337 s, 91 calls.
        _GetRestoreSettings = 3.337 s, 91 calls.
    AL = 2.807 s, 41 calls.
        GenerateSatelliteAssemblies = 2.807 s, 41 calls.
    RestoreTask = 1.744 s, 1 calls.
        Restore = 1.744 s, 1 calls.
    ResolvePackageAssets = 1.649 s, 35 calls.
        ResolvePackageAssets = 1.649 s, 35 calls.
    GenerateResource = 1.170 s, 22 calls.
        CoreResGen = 1.170 s, 22 calls.
    ResolvePackageFileConflicts = 1.167 s, 91 calls.
        _HandlePackageFileConflicts = 1.167 s, 91 calls.

Csc and ResolveAssemblyReference increased

Windows Update want to try install: KB5031323, KB5031455
After reboot

Top 10 most expensive tasks
    Csc = 5:46.193, 91 calls.
        CoreCompile = 5:46.193, 91 calls.
    ResolveAssemblyReference = 37.322 s, 91 calls.
        ResolveAssemblyReferences = 37.322 s, 91 calls.
    Exec = 3.760 s, 27 calls.
        PreBuild = 2.228 s, 15 calls.
        PreBuildEvent = 1.510 s, 11 calls.
        PostBuildEvent = 21 ms, 1 calls.
    AL = 1.530 s, 41 calls.
        GenerateSatelliteAssemblies = 1.530 s, 41 calls.
    Copy = 1.277 s, 324 calls.
        _CopyFilesMarkedCopyLocal = 1.106 s, 85 calls.
        CopyFilesToOutputDirectory = 144 ms, 203 calls.
        _CopyOutOfDateSourceItemsToOutputDirectory = 16 ms, 19 calls.
        _CopyAppConfigFile = 10 ms, 17 calls.
    RestoreTask = 1.273 s, 1 calls.
        Restore = 1.273 s, 1 calls.
    GetRestoreSettingsTask = 853 ms, 91 calls.
        _GetRestoreSettings = 853 ms, 91 calls.
    GenerateResource = 564 ms, 22 calls.
        CoreResGen = 564 ms, 22 calls.
    ResolvePackageAssets = 558 ms, 35 calls.
        ResolvePackageAssets = 558 ms, 35 calls.
    ResolvePackageFileConflicts = 425 ms, 91 calls.
        _HandlePackageFileConflicts = 425 ms, 91 calls.

One part of me is tempted to throw in the towel, point the finger at Windows 11, and consider installing a different operating system on these machines. Another part of me really want to know whats wrong here. Also tried with the new feature "Dev Drive" in hope of getting better RAR times.

[JanKrivanek]

Just out of curiosity - were you able to experiment with impact of server vs desktop OS on a same HW? MSFT Server OSes tend to have some perf characteristics (scheduling quantum length, etc.) that improve throughput (on a possible expense of responsiveness) of CPU intensive tasks. RAR should be very I/O bound - so probably red herring, but still would be interresting to see.

[AlexanderRydberg]

Sorry for the late reply @JanKrivanek!
Sadly, I gave up (this is haunting me in my dreams still) and just installed Windows 11 on them.

[JanKrivanek]

Hi @AlexanderRydberg I recalled your case when looking with @ladipro into https://developercommunity.visualstudio.com/t/Slow-Performance-During-Compilation/10556677 - if you ever go back to your experimentation with Win 11, can you check your status of Smart App Control? Setting it off might significantly speedup the build performance

[AlexanderRydberg]

I will try it right away!

Edit: Smart App Control was already disabled