GetCopyToOutputDirectoryItems perf

[rokonec]

Issue Description

Some build perf for a solution with only vc projects which don’t copy anything to the output dir and noticed that GetCopyToOutputDirectoryItems target time is pretty big without doing any actual copying.

Steps to Reproduce

Get \olgaark22\public\Build\Generated_250_250_250_5P2P.zip and run msbuild /m:10 /v:q /bl:Base_M010_MP010.binlog

Data

282473 ms  d:\olgaark\Generated_250_250_250_5P2P\gensln.sln   1 calls

Target Performance Summary:
122175 ms _GetCopyToOutputDirectoryItemsFromTransitiveProjectReferences 250 calls
122392 ms GetCopyToOutputDirectoryItems 250 calls
127669 ms GetReferencedVCProjectsInfo 250 calls
282461 ms Build 251 calls
425728 ms Link 250 calls
2058851 ms ClCompile 250 calls
34881129 ms ResolveProjectReferences 250 calls

Task Performance Summary:
1088 ms GenerateDesktopDeployRecipe 250 calls
122331 ms CallTarget 500 calls
416491 ms Link 250 calls
2048743 ms CL 250 calls
35412917 ms MSBuild 995 calls

Analysis

Hypothesis is that GetCopyToOutputDirectoryItems which is supposed to run on particular node is blocked by some other
build requests which have started on that node meanwhile.

Versions & Configurations

MSBuild version = "16.10.0-preview-21227-06+1d1fec7c4"

Regression?

Most probably not a regression.

Attach a binlog

See repro.

[rokonec]

Analysis

I have verified, by debugging repro and code survey, that following Rainer root cause analysis is indeed correct:

The actual execution time of GetCopyToOutputDirectoryItems is small (sequence point 9 to 10), but the time from requesting it (7) to completion (10) is much higher, because Unrelated.csproj was blocking Node2 during that time.

Experiment

By adding GetCopyToOutputDirectoryItems MSBuild task GetCopyToOutputDirectoryItems into ResolveProjectReferences it is assured that GetCopyToOutputDirectoryItems is cached and later request are satisfied by Scheduler build result cache.
This eliminates later waiting for project affinite node to finish its current build.

Microsoft Visual Studio\2022\Preview\MSBuild\Current\Bin\Microsoft.Common.CurrentVersion.targets was modified as follows:

<Target
      Name="ResolveProjectReferences"
      DependsOnTargets="PrepareProjectReferences"
      Returns="@(_ResolvedNativeProjectReferencePaths);@(_ResolvedProjectReferencePaths)">
    .
   ...

    <!-- Get items from child projects ASAP to avoid later node blocking by other project builds. -->
    <MSBuild
        Projects="@(_MSBuildProjectReferenceExistent)"
        Targets="$(_RecursiveTargetForContentCopying)"
        BuildInParallel="$(BuildInParallel)"
        Properties="%(_MSBuildProjectReferenceExistent.SetConfiguration); %(_MSBuildProjectReferenceExistent.SetPlatform); %(_MSBuildProjectReferenceExistent.SetTargetFramework)"
        Condition="'@(_MSBuildProjectReferenceExistent)' != '' and '$(_GetChildProjectCopyToOutputDirectoryItems)' == 'true' and '%(_MSBuildProjectReferenceExistent.Private)' != 'false' and '$(UseCommonOutputDirectory)' != 'true'"
        ContinueOnError="$(ContinueOnError)"
        SkipNonexistentTargets="true"
        RemoveProperties="%(_MSBuildProjectReferenceExistent.GlobalPropertiesToRemove)$(_GlobalPropertiesToRemoveFromProjectReferences)">

      <Output TaskParameter="TargetOutputs" ItemName="_AllChildProjectItemsWithTargetPath"/>

    </MSBuild>

    <!--
        Get manifest items from the (non-exe) built project references (to feed them into ResolveNativeReference).
        -->
    <MSBuild
        Projects="@(_MSBuildProjectReferenceExistent)"
        Targets="GetNativeManifest"

   ...

Reported GetCopyToOutputDirectoryItems Target duration has shrunk from 418 s to 25 s the build wall clock was only 3% faster (13 seconds). This is most probably result of GetCopyToOutputDirectoryItems blocked time often NOT being on critical path of MSBuild execution plan.

Possible problem solutions

1) Stub target in ResolveProjectReference

Stub target like AfterResolveProjectReferencePreCache would allow write extensions which would help solve this issue by preheating Scheduler build results cache. This would allow various project systems to customize it for their needs.

ResolveProjectReferences task runs 'Build;GetCopyToOutputDirectoryItems' targets by default.

We have to verify that result of of such MSBuild task run is cached in Scheduler per target and could be used to satisfy inevitable GetCopyToOutputDirectoryItems target build request.

2) Allow running subset of targets concurrently on a build node

Targets would have to declare if they are written the way that allows safe concurrent execution on busy nodes. Such target would be considered read-only and to not have any side effects (pure-function targets).
However, my simple prototype doing this was failing builds. I presume that it was because node was currently building same project for which we want to have GetCopyToOutputDirectoryItems target executed and the memory state which is needed for this target result was not yet consistent.

We would need to solve above issue by either waiting for build target of given project to be finished or by simple blocking while Node runs any exclusive builds of same project.

3) Storing CopyToOutputDirectoryItems in file system obj directory

This way getting this item list would be simply parsing related file without respecting project-node affinity. This would also eliminates recursive/transitive GetCopyToOutputDirectoryItems targets invocation. Additionally it might allows to further optimize incremental builds - VS proj system would copy files itself using content of this file when there would be no need to call MSBuild for example when ref-assemblies of parent projects stays untouched.
However, I am not sure if CopyToOutputDirectoryItems is stable for every kind of builds. I mean is it always identical regardless to which target project we need to copy files into?

4) Storing CopyToOutputDirectoryItems in a cache

Same as 3) but storing 'shareble' data from build in some interprocess non persistent cache. Various techniques are possible here. Easiest seems to be, to me, the 'Scheduler node' serving that purpose and hold the 'shareble' data.

[AraHaan]

Any progress on this?

[rokonec]

@AraHaan Could you kindly assist us in better understanding your use case? At the moment, we don't quite see its potential impact, and we'd appreciate your insights to help us grasp its significance better.

[AraHaan]

Let's say that if this could be done it can greatly help with improving the speed of my builds on some of my projects.

[rokonec]

Let's say that if this could be done it can greatly help with improving the speed of my builds on some of my projects.

My analysis shows "only" 3% performance gain for out test projects. You can try my experiment for your project to see if it improves overall build duration.

[ProVega]

I have a fast machine, with very fast disk; when doing a "Build" on a .NET 4.8 Web Project, we reference 16 other projects, each takes 120 to 400ms:

This run is pretty quick... but it does add up.

18> 185 ms C:\Source\Trunk_2023a\XXX.Module.Automation\XXX.Module.Automation.csproj 4 calls
18> 2 ms GetTargetFrameworks 1 calls
18> 1 ms GetTargetPath 1 calls
18> 0 ms GetNativeManifest 1 calls
18> 182 ms GetCopyToOutputDirectoryItems 1 calls
18> 191 ms C:\Source\Trunk_2023a\XXX.Module.TimeKeeping\XXX.Module.TimeKeeping.csproj 4 calls
18> 2 ms GetTargetFrameworks 1 calls
18> 1 ms GetTargetPath 1 calls
18> 0 ms GetNativeManifest 1 calls
18> 188 ms GetCopyToOutputDirectoryItems 1 calls
18> 193 ms C:\Source\Trunk_2023a\XXX.Module.Backup\XXX.Module.Backup.csproj 4 calls

[baronfel]

@AraHaan / @ProVega - are you able to try the change that @rokonec mentioned above and take a binlog to compare/contract the time spent in GetCopyToOutputDirectoryItems across your projects?

[maridematte]

@AraHaan / @ProVega - are you still trying these changes?