Analyze Property And Item Evaluation Phase Performace

[TFTomSun]

We have the situation that some builds seem to take quite long, but we can't really figure out why they are slow. The structured log viewer shows the top ten tasks already But Tasks seem not to be the root cause for the overall build time of over one second. Is it possible to analyze the performance beyond the pure task execution time? Does the structure logger have some feature that could support such analysis?

Edit: I found now a clear indicator that the evaluation phase it what takes so long: But can I dig there more into the details, what actually takes so long?

Edit 2: Another issue I recognized are builds like this one:

It takes 16 seconds in total (thats also the total duration) but after 10 seconds it seems to be done. In the tracing is nothing visible after 10 seconds.

[KirillOsenkov]

You can run msbuild /bl /profileevaluation and it will show the perf in the tree:

Read more details at: https://github.com/dotnet/msbuild/blob/main/documentation/evaluation-profiling.md

[TFTomSun]

cool, that will be helpful. Is it possible to activate that profiling for build logs that are produced by VisualStudio and the Build Logging Extensions as well?

Any ideas how those 6 seconds of idle at the end of the build can happen?

Edit: @KirillOsenkov Thanks alot for the hint about the profileevaluation flag. It helped me to find a big amount of web asset files that we consume through a package. The StaticWebAsset handling has already a huge impact on the the evaluation phase and I assume that the long time after the build is probably some copy operation which is not tracked by the build logging. When I remove that package the build is much faster.

[KirillOsenkov]

Yes, see here for a better way to get good binlogs from Visual Studio without needing the Extension: https://msbuildlog.com/#MSBUILDDEBUGENGINE

[KirillOsenkov]

Slowdowns in evaluation are usually to glob expansion (like you have **\* somewhere), it scans the disk and can take a long time for large folders.

[TFTomSun]

I identified already an issue with a large number of web assets and razorclasslibraries and created an issue here: https://github.com/dotnet/aspnetcore/issues/46272

However even with MSBUILDDEBUGENGINE=1, I don't see what is happen at the end of the build. I assume it's related to the amount of static web asset files, but I would like to see something to be sure. In the small repro repo that I mentioned in the issue above, I don't see such idle times. I think that would also help Microsoft to analyse the issue.

Edit: btw. I see those idle times only in builds from within VisualStudio. When I build the same solution with the Visual Studios msbuild, the idle times are not there.

[KirillOsenkov]

Try using PerfView to profile. It will tell you what is going on in your entire system.

[KirillOsenkov]

Don't think there's anything else I can do here on the viewer side, so closing.