Analyzing Visual Studio Build Performance

Every now and again, your build time gets so long you have to investigate what the cause is. Since Visual Studio uses MSBuild, it is possible to get very detailed build information.

The first step is getting into diagnostic mode. This will print out way too much information, but it is the only mode that prints out execution summaries for each project. To get into diagnostics mode, simply go to Tools -> Options -> Projects and Solutions -> Build and Run. From there, you can change the MSBuild verbosity to diagnostic.

12-22-2009 7-44-06 PM
12-22-2009 7-45-08 PM

Now just build (or rebuild). Then copy the build output to a txt file and save it somewhere.

12-22-2009 7-50-52 PM

The only problem with the output is the amount of information (300K lines on a rebuild of a medium size project). It has ton’s of valuable information, but an easy way to process it is needed. The biggest value, in my opinion, is the section at the end of every project where the Summary information about projects, targets, and tasks are displayed. To help retrieve this info, I wrote a quick little Powershell script.

 
param
(
    [string] $file = ""
)
 
if(!(test-path $file)){
    throw "$file not found"
}
 
function accumulate_and_print_project_info(){
    begin{
        $curr_project = ""
        $should_print = $false
    }
    process{
 
 
        if($_ -match "----- (re)?build (all )?started: project: (.*) -----"){
            $curr_project = $matches[3]
            "----- $curr_project -----"
            $should_print = $false
        }elseif($curr_project -and !$should_print -and $_.EndsWith("Summary:")){
            $_
            $should_print = $true
        }elseif($curr_project -and $should_print -and $_ -eq ""){
            $should_print = $false
        }elseif($should_print){
            $_
        }
    }
}
 
gc $file | accumulate_and_print_project_info

The output is going to look something like the following.

----- ControlPanel, Configuration: Development Any CPU -----
Project Performance Summary:
     2672 ms  C:\Users\brian.hartsock\Documents\Visual Studio 2008\Projects\Api\cp3\ControlPanel\ControlPanel.csproj   1 calls
Target Performance Summary:
        0 ms  CreateSatelliteAssemblies                  1 calls
        0 ms  _ComputeNonExistentFileProperty            1 calls
        0 ms  Clean                                      1 calls
        0 ms  _AfterCompileWinFXInternal                 1 calls
        0 ms  BeforeCompile                              1 calls
        0 ms  BeforeClean                                1 calls
        0 ms  AfterBuild                                 1 calls
        0 ms  GetTargetPath                              1 calls
        0 ms  _CheckForCompileOutputs                    1 calls
        0 ms  EntityDeploy                               1 calls
        0 ms  ResolveVCProjectReferences                 1 calls
        0 ms  _SetEmbeddedWin32ManifestProperties        1 calls
        0 ms  StyleCopForceFullAnalysis                  1 calls
        0 ms  CleanPublishFolder                         1 calls
        0 ms  BeforeBuild                                1 calls
        0 ms  CoreResGen                                 1 calls
        0 ms  BeforeRebuild                              1 calls
        0 ms  _CopySourceItemsToOutputDirectory          1 calls
        0 ms  AfterResGen                                1 calls
        0 ms  Build                                      1 calls
        0 ms  SetWin32ManifestProperties                 1 calls
        0 ms  AssignTargetPaths                          1 calls
        0 ms  CoreBuild                                  1 calls
        0 ms  AfterResolveReferences                     1 calls
        0 ms  Compile                                    1 calls
        0 ms  ResGen                                     1 calls
        0 ms  AfterClean                                 1 calls
        0 ms  Rebuild                                    1 calls
        0 ms  PrepareResourceNames                       1 calls
        0 ms  BuildOnlySettings                          1 calls
        0 ms  PrepareResources                           1 calls
        0 ms  CleanReferencedProjects                    1 calls
        0 ms  AfterMarkupCompilePass1                    1 calls
        0 ms  FileClassification                         1 calls
        0 ms  AfterCompile                               1 calls
        0 ms  CompileRdlFiles                            1 calls
        0 ms  BeforeResolveReferences                    1 calls
        0 ms  CreateCustomManifestResourceNames          1 calls
        0 ms  ResolveReferences                          1 calls
        0 ms  DesignTimeMarkupCompilation                1 calls
        0 ms  AfterRebuild                               1 calls
        0 ms  GetReferenceAssemblyPaths                  1 calls
        0 ms  PrepareForRun                              1 calls
        0 ms  AfterCompileWinFX                          1 calls
        0 ms  BeforeResGen                               1 calls
        1 ms  PrepareRdlFiles                            1 calls
        1 ms  GetCopyToOutputDirectoryItems              1 calls
        1 ms  SplitResourcesByCulture                    1 calls
        1 ms  _SplitProjectReferencesByFileExistence     1 calls
        1 ms  _GenerateCompileInputs                     1 calls
        1 ms  _GenerateSatelliteAssemblyInputs           1 calls
        1 ms  GetWinFXPath                               1 calls
        1 ms  EntityClean                                1 calls
        1 ms  _CheckForInvalidConfigurationAndPlatform   1 calls
        1 ms  ResolveProjectReferences                   1 calls
        1 ms  PrepareForBuild                            1 calls
        3 ms  GetFrameworkPaths                          1 calls
        8 ms  CoreClean                                  1 calls
       14 ms  IncrementalClean                           1 calls
       17 ms  CopyFilesToOutputDirectory                 1 calls
       17 ms  _CleanGetCurrentAndPriorFileWrites         1 calls
       66 ms  ResolveAssemblyReferences                  1 calls
      399 ms  _CopyFilesMarkedCopyLocal                  1 calls
      519 ms  StyleCop                                   1 calls
      636 ms  CoreCompile                                1 calls
      974 ms  PostBuildEvent                             1 calls
Task Performance Summary:
        0 ms  Delete                                     2 calls
        0 ms  Message                                    6 calls
        0 ms  EntityDeploy                               1 calls
        0 ms  GetFrameworkSdkPath                        1 calls
        0 ms  CreateProperty                             1 calls
        0 ms  AssignTargetPath                           5 calls
        0 ms  MakeDir                                    2 calls
        1 ms  ConvertToAbsolutePath                      1 calls
        1 ms  AssignCulture                              1 calls
        1 ms  GetWinFXPath                               1 calls
        1 ms  FindAppConfigFile                          1 calls
        1 ms  ReadLinesFromFile                          2 calls
        1 ms  EntityClean                                1 calls
        2 ms  CreateItem                                 3 calls
        2 ms  WriteLinesToFile                           2 calls
        3 ms  GetFrameworkPath                           2 calls
       13 ms  RemoveDuplicates                           3 calls
       20 ms  FindUnderPath                              7 calls
       66 ms  ResolveAssemblyReference                   1 calls
      415 ms  Copy                                       6 calls
      515 ms  StyleCopTask                               1 calls
      635 ms  Csc                                        1 calls
      973 ms  Exec                                       1 calls

Now you should have all the data you need to figure out what is taking so long to build your project.