The enterprise builds are huge and take a significant amount of build time. MSBuild offers an option to track the performance of each task and target executed in the build process which would be quite helpful for builders to identify the performance problems and improve the build time. I’m attempting to provide some details on how this can be plugged into TeamBuild.
MSBuild loggers have an option called PerformanceSummary to log this data. The user will need to add the following command line option to the msbuild process that runs on the build machine (refer here for more details on how to pass additional options to msbuild command line in TeamBuild):
/logger:FileLogger,Microsoft.Build.Engine;logfile=buildperf.log;encoding=Unicode;performancesummary
This creates the build log file that contains performance data buildperf.log at <builddir>\<teamproject>\<buildtype>\buildtype on the build machine. Currently, I could not find a way to upload this to drop location, because it needs to be uploaded after msbuild process exits and we currently don’t have a way to do this. BTW, this option is enabled in 'diagnostic' mode. So, user can pass '/v:diag' to msbuild command line and get this data in BuildLog.txt itself. It will have lots of other noise though.
Here is a snapshot of the performance data that msbuild process would log:
Project Performance Summary:
1302 ms d:\builddir\TestProject\Take1\Sources\WindowsApplication1\WindowsApplication1\WindowsApplication1.csproj 1 calls
1593 ms d:\builddir\TestProject\Take1\Sources\WindowsApplication2\WindowsApplication2.sln 1 calls
18549 ms d:\builddir\TestProject\Take1\BuildType\TFSBuild.proj 1 calls
Target Performance Summary:
* ms Build 1 calls
* ms CoreCompile 1 calls
0 ms Clean 1 calls
0 ms BeforeResGen 1 calls
0 ms PostBuild 1 calls
0 ms BuildNumberOverrideTarget 1 calls
0 ms BeforeClean 1 calls
0 ms _CheckForInvalidConfigurationAndPlatform 1 calls
0 ms BeforeDropBuild 1 calls
0 ms GetCopyToOutputDirectoryItems 1 calls
0 ms PackageBinaries 1 calls
0 ms _CleanGetCurrentAndPriorFileWrites 1 calls
0 ms GetTargetPath 1 calls
0 ms PreBuild 1 calls
0 ms _CopyFilesMarkedCopyLocal 1 calls
0 ms _CheckForCompileOutputs 1 calls
0 ms AssignTargetPaths 1 calls
0 ms Compile 2 calls
0 ms BeforeBuild 1 calls
0 ms _CopySourceItemsToOutputDirectory 1 calls
0 ms AfterBuild 1 calls
0 ms AfterResGen 1 calls
0 ms AfterResolveReferences 1 calls
0 ms Test 1 calls
0 ms AfterCompile 2 calls
0 ms CoreBuild 1 calls
0 ms GetRedistLists 1 calls
0 ms PrepareResources 1 calls
0 ms AfterEndToEndIteration 1 calls
0 ms AfterLabel 1 calls
0 ms ResolveReferences 1 calls
0 ms BeforeEndToEndIteration 1 calls
0 ms ValidateSolutionConfiguration 1 calls
0 ms BuildOnlySettings 1 calls
0 ms DropBuild 1 calls
0 ms ResGen 1 calls
0 ms PrepareResourceNames 1 calls
0 ms SplitResourcesByCulture 1 calls
0 ms BeforeResolveReferences 1 calls
0 ms AfterGet 1 calls
0 ms TeamBuild 1 calls
0 ms PrepareRdlFiles 1 calls
0 ms CompileRdlFiles 1 calls
0 ms AfterTest 1 calls
0 ms BeforeGet 1 calls
0 ms AfterDropBuild 1 calls
0 ms BeforeLabel 1 calls
0 ms EndToEndIteration 1 calls
0 ms PrepareForRun 1 calls
0 ms AfterClean 1 calls
0 ms GetFrameworkPaths 1 calls
10 ms CopyFilesToOutputDirectory 1 calls
10 ms PrepareForBuild 1 calls
10 ms CopyLogFiles 1 calls
10 ms CreateManifestResourceNames 1 calls
10 ms IncrementalClean 1 calls
20 ms InitializeBuild 1 calls
40 ms CoreClean 1 calls
50 ms CoreResGen 1 calls
50 ms CoreDropBuild 1 calls
150 ms ResolveAssemblyReferences 1 calls
150 ms BeforeTest 1 calls
170 ms InitializeEndToEndIteration 1 calls
180 ms BeforeCompile 2 calls
220 ms CheckSettingsForEndToEndIteration 1 calls
1332 ms WindowsApplication2 1 calls
1462 ms CoreLabel 1 calls
2354 ms InitializeWorkspace 1 calls
3976 ms CoreGet 1 calls
5318 ms GetChangeSetsAndUpdateWorkItems 1 calls
(* = timing was not recorded because of reentrancy)
Task Performance Summary:
* ms MSBuild 1 calls
0 ms RemoveDuplicates 2 calls
0 ms CreateCSharpManifestResourceName 1 calls
0 ms GetFrameworkSDKPath 1 calls
0 ms FindUnderPath 5 calls
0 ms ReadLinesFromFile 1 calls
0 ms AssignTargetPath 5 calls
0 ms AssignCulture 1 calls
0 ms CreateProperty 12 calls
0 ms GetFrameworkPath 1 calls
10 ms MakeDir 5 calls
10 ms Delete 1 calls
10 ms TeamBuildMessage 3 calls
10 ms CreateItem 17 calls
20 ms RemoveDir 1 calls