Slow Razor Build Times

[mkArtakMSFT]

From @barrettg on June 5, 2018 16:45

I am experiencing very slow build times after installing the 2.1 SDK on my Windows machine. I'm creating a new project with dotnet new mvc -au Individual and then building with dotnet build /clp:performancesummary. It seems the Razor build engine is the source of the problem:

Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 47.36 ms for C:\GitHub\test\test.csproj.
  test -> C:\GitHub\test\bin\Debug\netcoreapp2.1\test.dll
  test -> C:\GitHub\test\bin\Debug\netcoreapp2.1\test.Views.dll

Project Evaluation Performance Summary:
      294 ms  C:\GitHub\test\test.csproj                 3 calls

Project Performance Summary:
    43474 ms  C:\GitHub\test\test.csproj                 7 calls
                260 ms  Restore                                    1 calls
                  0 ms  _IsProjectRestoreSupported                 2 calls
                  1 ms  _GenerateRestoreProjectPathWalk            1 calls
                 21 ms  _GenerateRestoreGraphProjectEntry          1 calls
                  4 ms  _GenerateProjectRestoreGraph               1 calls
              43187 ms  Build                                      1 calls

Target Performance Summary:
        0 ms  ResGen                                     1 calls
        0 ms  _RazorPrepareForRun                        1 calls
        0 ms  PrepareResourceNames                       1 calls
        0 ms  PrepareForRazorCompile                     1 calls
        0 ms  Compile                                    1 calls
        0 ms  PrepareResources                           1 calls
        0 ms  GetReferenceAssemblyPaths                  1 calls
        0 ms  ResolvePackageDependenciesForBuild         1 calls
        0 ms  ResolveRazorCompileInputs                  1 calls
        0 ms  PrepareProjectReferences                   1 calls
        0 ms  BeforeBuild                                1 calls
        0 ms  AfterBuild                                 1 calls
        0 ms  _GenerateRazorAssemblyInfo                 1 calls
        0 ms  _CopySourceItemsToOutputDirectory          1 calls
        0 ms  GenerateRazorTargetAssemblyInfo            1 calls
        0 ms  CreateSatelliteAssemblies                  1 calls
        0 ms  GetFrameworkPaths                          1 calls
        0 ms  BeforeResGen                               1 calls
        0 ms  InitializeSourceControlInformation         1 calls
        0 ms  SetWin32ManifestProperties                 1 calls
        0 ms  GenerateUserSecretsAttribute               1 calls
        0 ms  CreateCustomManifestResourceNames          1 calls
        0 ms  PrepareForRun                              1 calls
        0 ms  BeforeCompile                              1 calls
        0 ms  BeforeResolveReferences                    1 calls
        0 ms  GenerateAssemblyInfo                       1 calls
        0 ms  CoreBuild                                  1 calls
        0 ms  AfterCompile                               1 calls
        0 ms  AfterResGen                                1 calls
        0 ms  RazorCompile                               1 calls
        0 ms  AfterResolveReferences                     1 calls
        0 ms  AddSourceRevisionToInformationalVersion    1 calls
        0 ms  RazorGenerate                              1 calls
        0 ms  _GetRestoreSettingsCurrentProject          1 calls
        0 ms  _GenerateRestoreProjectPathItemsCurrentProject   1 calls
        0 ms  PrepareForRazorGenerate                    1 calls
        0 ms  GetTargetPath                              1 calls
        0 ms  _GenerateProjectRestoreGraph               1 calls
        0 ms  _DefaultMicrosoftNETPlatformLibrary        1 calls
        0 ms  _GenerateRestoreGraphProjectEntry          1 calls
        0 ms  _GenerateRestoreDependencies               1 calls
        0 ms  _GenerateProjectRestoreGraphCurrentProject   1 calls
        0 ms  BuildOnlySettings                          1 calls
        0 ms  EnableIntermediateOutputPathMismatchWarning   1 calls
        0 ms  EnsureTFMCompatibility                     1 calls
        0 ms  _CheckForUnsupportedSelfContained          1 calls
        0 ms  IncludeTransitiveProjectReferences         1 calls
        0 ms  Build                                      1 calls
        0 ms  _SetTargetFrameworkMonikerAttribute        1 calls
        0 ms  ExpandSDKReferences                        1 calls
        0 ms  ResolveSDKReferences                       1 calls
        0 ms  ResolveLockFileAnalyzers                   1 calls
        0 ms  _ResolveGeneratedRazorCompileInputs        1 calls
        0 ms  _BeforeVBCSCoreCompile                     1 calls
        0 ms  CollectPackageReferences                   2 calls
        0 ms  _GetRestoreSettingsOverrides               1 calls
        0 ms  ComputeDependencyFileCompilerOptions       1 calls
        0 ms  _GetRestoreSettingsPerFramework            1 calls
        0 ms  _CheckForObsoleteDotNetCliToolReferences   2 calls
        0 ms  _CopyReferenceOnlyAssembliesForBuild       1 calls
        0 ms  _SplitProjectReferencesByFileExistence     1 calls
        0 ms  RazorGetAssemblyAttributes                 1 calls
        0 ms  _CheckForUnsupportedNETCoreVersion         3 calls
        0 ms  _GetRestoreProjectStyle                    2 calls
        0 ms  _IsProjectRestoreSupported                 1 calls
        0 ms  _GetProjectJsonPath                        2 calls
        0 ms  GetAssemblyAttributes                      1 calls
        0 ms  _GenerateRestoreProjectPathItems           1 calls
        0 ms  _GenerateCompileInputs                     1 calls
        0 ms  _ResolveRazorTargetPath                    1 calls
        0 ms  GetRazorTargetAssemblyAttributes           1 calls
        0 ms  GetTargetPathWithTargetPlatformMoniker     1 calls
        0 ms  _RazorGetCopyToOutputDirectoryItems        1 calls
        0 ms  _GenerateSatelliteAssemblyInputs           1 calls
        0 ms  _ComputeNETCoreBuildOutputFiles            1 calls
        0 ms  _CheckForCompileOutputs                    1 calls
        0 ms  CoreResGen                                 1 calls
        0 ms  GetAssemblyVersion                         1 calls
        0 ms  _GenerateRestoreSpecs                      1 calls
        0 ms  _GenerateRestoreProjectPathWalk            1 calls
        0 ms  _ResolveRazorGenerateOutputs               1 calls
        0 ms  _CheckForInvalidConfigurationAndPlatform   1 calls
        0 ms  ResolveReferences                          1 calls
        0 ms  _GenerateRestoreProjectSpec                1 calls
        0 ms  _GenerateRestoreProjectPathItemsPerFramework   1 calls
        0 ms  _GetProjectReferenceTargetFrameworkProperties   1 calls
        0 ms  SplitResourcesByCulture                    1 calls
        0 ms  AssignRazorGenerateTargetPaths             1 calls
        1 ms  ResolveAssemblyReferenceRazorGenerateInputs   1 calls
        1 ms  _CollectTargetFrameworkForTelemetry        1 calls
        1 ms  CoreGenerateAssemblyInfo                   1 calls
        1 ms  GenerateTargetFrameworkMonikerAttribute    1 calls
        1 ms  ResolveRazorConfiguration                  1 calls
        1 ms  CoreGenerateRazorTargetAssemblyInfo        1 calls
        1 ms  _CreateRazorAssemblyInfoInputsCacheFile    1 calls
        1 ms  CreateGeneratedAssemblyInfoInputsCacheFile   1 calls
        1 ms  CheckForDuplicateItems                     1 calls
        1 ms  CoreGenerateUserSecretsAttribute           1 calls
        1 ms  GetCopyToOutputDirectoryItems              1 calls
        1 ms  _GetRestoreTargetFrameworksOutput          1 calls
        1 ms  _HashRazorGenerateInputs                   1 calls
        1 ms  _CreateRazorTargetAssemblyInfoInputsCacheFile   1 calls
        1 ms  ResolveRazorGenerateInputs                 1 calls
        1 ms  _SetEmbeddedWin32ManifestProperties        1 calls
        1 ms  _ComputeReferenceAssemblies                1 calls
        1 ms  AssignTargetPaths                          1 calls
        1 ms  IncrementalClean                           1 calls
        1 ms  _CoreGenerateRazorAssemblyInfo             1 calls
        1 ms  ResolveLockFileReferences                  1 calls
        2 ms  CopyFilesToOutputDirectory                 1 calls
        2 ms  _GenerateCompileDependencyCache            1 calls
        2 ms  _GetAllRestoreProjectPathItems             1 calls
        3 ms  CheckForImplicitPackageReferenceOverrides   2 calls
        3 ms  _RazorCopyFilesToOutputDirectory           1 calls
        3 ms  _CopyOutOfDateSourceItemsToOutputDirectory   1 calls
        3 ms  _GenerateProjectRestoreGraphPerFramework   1 calls
        3 ms  _CleanGetCurrentAndPriorFileWrites         1 calls
        4 ms  PrepareForBuild                            1 calls
        5 ms  _GenerateDotnetCliToolReferenceSpecs       1 calls
        5 ms  RunProduceContentAssets                    1 calls
        6 ms  _LoadRestoreGraphEntryPoints               1 calls
       13 ms  _GetRestoreSettings                        1 calls
       25 ms  _HandlePackageFileConflicts                1 calls
       27 ms  _GenerateRestoreGraph                      1 calls
       28 ms  FindReferenceAssembliesForReferences       1 calls
       28 ms  ResolveProjectReferences                   1 calls
       36 ms  GenerateBuildRuntimeConfigurationFiles     1 calls
       74 ms  GenerateBuildDependencyFile                1 calls
       75 ms  _FilterRestoreGraphProjectInputItems       1 calls
       86 ms  ResolvePackageAssets                       1 calls
      109 ms  ResolveAssemblyReferences                  1 calls
      141 ms  Restore                                    1 calls
      270 ms  RazorCoreCompile                           1 calls
      995 ms  CoreCompile                                1 calls
    20568 ms  RazorCoreGenerate                          1 calls
    20920 ms  ResolveTagHelperRazorGenerateInputs        1 calls

Task Performance Summary:
        0 ms  GetAssemblyVersion                         1 calls
        0 ms  AssignCulture                              1 calls
        0 ms  ReadLinesFromFile                          1 calls
        0 ms  Delete                                     1 calls
        0 ms  GetRestoreProjectReferencesTask            1 calls
        0 ms  FindAppConfigFile                          1 calls
        0 ms  Telemetry                                  1 calls
        0 ms  GetFrameworkPath                           1 calls
        0 ms  Message                                    7 calls
        0 ms  FindInList                                 1 calls
        1 ms  JoinItems                                  1 calls
        1 ms  CheckForDuplicateItems                     3 calls
        1 ms  GetProjectTargetFrameworksTask             1 calls
        1 ms  FindUnderPath                              5 calls
        1 ms  ConvertToAbsolutePath                      3 calls
        1 ms  AssignTargetPath                           6 calls
        1 ms  Hash                                       5 calls
        1 ms  CheckForImplicitPackageReferenceOverrides   2 calls
        2 ms  WriteCodeFragment                          4 calls
        2 ms  Touch                                      2 calls
        2 ms  GetRestorePackageReferencesTask            1 calls
        3 ms  RemoveDuplicates                           7 calls
        3 ms  WriteLinesToFile                           6 calls
        4 ms  GetRestoreDotnetCliToolsTask               1 calls
        5 ms  ProduceContentAssets                       1 calls
        5 ms  WarnForInvalidProjectsTask                 1 calls
        5 ms  Copy                                       6 calls
        5 ms  MakeDir                                    4 calls
       13 ms  GetRestoreSettingsTask                     1 calls
       20 ms  ResolvePackageFileConflicts                1 calls
       36 ms  GenerateRuntimeConfigurationFiles          1 calls
       74 ms  GenerateDepsFile                           1 calls
       86 ms  ResolvePackageAssets                       1 calls
       87 ms  MsBuild                                    7 calls
      108 ms  ResolveAssemblyReference                   1 calls
      141 ms  RestoreTask                                1 calls
     1262 ms  Csc                                        2 calls
    20566 ms  RazorGenerate                              1 calls
    20917 ms  RazorTagHelper                             1 calls

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:43.74

_Copied from original issue: aspnet/Home#3199_

[mkArtakMSFT]

From @pranavkm on June 5, 2018 17:26

cc @mkArtakMSFT. Issue belongs to Razor

[mkArtakMSFT]

@ajaybhargavb, can you please investigate this? Thanks!

[henkmollema]

@mkArtakMSFT I'm experiencing the same behavior, even when the changes are not in any .cshtml file (just .cs ones).

      667 ms  RazorCoreCompile                           1 calls
     1527 ms  Restore                                    1 calls
     3351 ms  CoreCompile                                1 calls
    21487 ms  ResolveTagHelperRazorGenerateInputs        1 calls
    26476 ms  Build                                      2 calls

Build times vary from 20 to 50 seconds. It makes developing pretty unbearable. The behavior seems not to be consistent though.

dotnet --info output:

λ dotnet --info
.NET Core SDK (reflecting any global.json):
 Version:   2.1.300
 Commit:    adab45bf0c

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.16299
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\2.1.300\

Host (useful for support):
  Version: 2.1.0
  Commit:  caa7b7e2ba

.NET Core SDKs installed:
  2.1.104 [C:\Program Files\dotnet\sdk]
  2.1.200 [C:\Program Files\dotnet\sdk]
  2.1.201 [C:\Program Files\dotnet\sdk]
  2.1.300-preview2-008533 [C:\Program Files\dotnet\sdk]
  2.1.300-rc1-008673 [C:\Program Files\dotnet\sdk]
  2.1.300 [C:\Program Files\dotnet\sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.1.0-preview1-final [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.0-preview2-final [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.0-rc1-final [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.0-preview1-final [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.0-preview2-final [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.0-rc1-final [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.0.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.0.6 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.0.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0-preview1-26216-03 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0-preview2-26406-04 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0-rc1 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]

[henkmollema]

The slow build times reproduce in Visual Studio 15.7.3 as well.

[ajaybhargavb]

@henkmollema, are you creating your project with dotnet new mvc -au Individual as well?

[henkmollema]

@ajaybhargavb it repros with an existing application as well as with any clean dotnet new application with Razor files (mvc, mvc -au Individual, angular, etc). dotnet new web (empty web app) builds quickly as expected.

[henkmollema]

Might be useful: when you cancel the build with CTRL + C it fails with:

Build FAILED.

C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018: The "RazorTagHelper" task failed unexpectedly. [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018: System.OperationCanceledException: The operation was canceled. [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at System.Threading.CancellationToken.ThrowOperationCanceledException() [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at System.Threading.ManualResetEventSlim.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken) [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at System.Threading.Tasks.Task.SpinThenBlockingWait(Int32 millisecondsTimeout, CancellationToken cancellationToken) [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at System.Threading.Tasks.Task.InternalWaitCore(Int32 millisecondsTimeout, CancellationToken cancellationToken) [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken) [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at Microsoft.AspNetCore.Razor.Tasks.DotNetToolTask.TryExecuteOnServer(String pathToTool, String responseFileCommands, String commandLineCommands, Int32& result) [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at Microsoft.AspNetCore.Razor.Tasks.DotNetToolTask.ExecuteTool(String pathToTool, String responseFileCommands, String commandLineCommands) [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at Microsoft.Build.Utilities.ToolTask.Execute() [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at Microsoft.Build.BackEnd.TaskExecutionHost.Microsoft.Build.BackEnd.ITaskExecutionHost.Execute() [C:\tmp\tmpmvc\tmpmvc.csproj]
C:\Program Files\dotnet\sdk\NuGetFallbackFolder\microsoft.aspnetcore.razor.design\2.1.0\build\netstandard2.0\Microsoft.AspNetCore.Razor.Design.CodeGeneration.targets(69,5): error MSB4018:    at Microsoft.Build.BackEnd.TaskBuilder.ExecuteInstantiatedTask(ITaskExecutionHost taskExecutionHost, TaskLoggingContext taskLoggingContext, TaskHost taskHost, ItemBucket bucket, TaskExecutionMode howToExecuteTask) [C:\tmp\tmpmvc\tmpmvc.csproj]

[henkmollema]

This issue does not reproduce with 2.0 tooling (e.g. 2.1.201)

[ajaybhargavb]

The behavior seems not to be consistent though.

I am having a hard time reproducing it. How frequently does this happen?

[henkmollema]

It seems to be consistent since I've said that, haha. 😅 It reproduces with any dotnet new mvc && dotnet build:

C:\tmp\tmpmvc1
λ dotnet new mvc && dotnet build
The template "ASP.NET Core Web App (Model-View-Controller)" was created successfully.
This template contains technologies from parties other than Microsoft, see https://aka.ms/aspnetcore-template-3pn-210 for details.

Processing post-creation actions...
Running 'dotnet restore' on C:\tmp\tmpmvc1\tmpmvc1.csproj...
  Restoring packages for C:\tmp\tmpmvc1\tmpmvc1.csproj...
  Generating MSBuild file C:\tmp\tmpmvc1\obj\tmpmvc1.csproj.nuget.g.props.
  Generating MSBuild file C:\tmp\tmpmvc1\obj\tmpmvc1.csproj.nuget.g.targets.
  Restore completed in 1,16 sec for C:\tmp\tmpmvc1\tmpmvc1.csproj.

Restore succeeded.

Microsoft (R) Build Engine version 15.7.179.6572 for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 55,6 ms for C:\tmp\tmpmvc1\tmpmvc1.csproj.
  tmpmvc1 -> C:\tmp\tmpmvc1\bin\Debug\netcoreapp2.1\tmpmvc1.dll
  tmpmvc1 -> C:\tmp\tmpmvc1\bin\Debug\netcoreapp2.1\tmpmvc1.Views.dll

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:45.32