Performance: reduce overhead of computing full path for items from globs

[lifengl]

Based on investigating performance trace to load Roslyn.sln, I looked into the time spent in CPS's UpdateSnapshotCoreAsync, almost 30% thread time in this function is to calculate FullPath of project items.

Because those items are coming from globs, I wonder the path is naturally normalized, and we can reduce some of the overhead here.

Name                                                                 	                                        Inc %	  Inc	           Inc Ct
microsoft.build.ni!FileUtilities.GetFullPath                        	                       28.1	          405.567	  592
+ microsoft.build.ni!FileUtilities.NormalizePath                     	                       19.3	           277.811	  267
+ system.ni!System.Text.RegularExpressions.Regex.Match(System.String)	 5.9	           84.554	  209
+ mscorlib.ni!System.IO.Path.Combine(System.String, System.String)   	 1.5	           22.189	   62

[lifengl]

Include @cdmihai & @davkean to the thread. The rule snapshots logic is a slow portion of the code after the project evaluation phase.

[cdmihai]

Is this evaluation, or design time builds? Could you please also post more of the backtraces to see where GetFullPath is called from (preferably up to Project), or upload the perfiew trace?

[lifengl]

This happens after the project evaluation inside VS. During that phase, we extra information from msbuild evaluation results based on rules defined in the project system. The overall time is much smaller than the evaluation time, so I would consider this lower priority than improving the evaluation time.

On the other side, we start to look beyond the evaluation time to see what we can do to make loading a project faster, and this turns out to be one major block we want to make more efficient during the critical path in the loading phase. I will share the Roslyn.sln loading ETW trace with you (or anyone can take this trace with PerfView).

To look into this time: Open the thread time window in perfView, (select devenv, and remove grouParts setting) and find UpdateSnapshotCoreAsync stack, and open it in the Callees window (this will aggregate time spent in this method). Use context menu to drill into it.

After that, you can see the time spent inside this function, and the top cost is inside FileUtilities.GetFullPath.

The caller of this method:

Name | Inc % | Inc | Inc Ct
-- | -- | -- | --
microsoft.build.ni!FileUtilities.GetFullPath | 28.1 | 405.567 | 592
+ microsoft.build.ni!Microsoft.Build.Shared.FileUtilities+ItemSpecModifiers.GetItemSpecModifier(System.String, System.String, System.String, System.String, System.String ByRef) | 28.1 | 405.567 | 592
+ microsoft.build.ni!Microsoft.Build.Shared.FileUtilities+ItemSpecModifiers.GetItemSpecModifier(System.String, System.String, System.String, System.String, System.String ByRef) | 22.2 | 319.395 | 454
\|+ microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetBuiltInMetadataEscaped(System.String) | 22.1 | 318.429 | 445
\|\|+ microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetMetadataEscaped(System.String) | 22.1 | 318.429 | 445
\|\| + microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetMetadata(System.String) | 22.1 | 318.429 | 445
\|\|  + microsoft.visualstudio.projectsystem.implementation.ni!ProjectEvaluationSubscriptionService.BuildItemsSnapshot | 22.1 | 318.429 | 445
\|+ microsoft.build.ni!Microsoft.Build.Shared.FileUtilities+ItemSpecModifiers.GetItemSpecModifier(System.String, System.String, System.String, System.String, System.String ByRef) | 0.1 | 0.966 | 9
\| + microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetBuiltInMetadataEscaped(System.String) | 0.1 | 0.966 | 9
\|  + microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetMetadataEscaped(System.String) | 0.1 | 0.966 | 9
\|   + microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetMetadata(System.String) | 0.1 | 0.966 | 9
\|    + microsoft.visualstudio.projectsystem.implementation.ni!ProjectEvaluationSubscriptionService.BuildItemsSnapshot | 0.1 | 0.966 | 9
+ microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetBuiltInMetadataEscaped(System.String) | 6.0 | 86.172 | 138
+ microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetMetadataEscaped(System.String) | 6.0 | 86.172 | 138
+ microsoft.build.ni!Microsoft.Build.Execution.ProjectItemInstance+TaskItem.GetMetadata(System.String) | 6.0 | 86.172 | 138
+ microsoft.visualstudio.projectsystem.implementation!ProjectInstanceItemProperties.GetEvaluatedPropertyValue | 6.0 | 86.172 | 138