Integrate generator times into /reportAnalyzer #61661

jaredpar · 2022-06-02T18:45:27Z

This integrates the source generator timing work, #60267, into the
/reportAnalyzer framework. A sample of the new output from a simple
net7.0 console app is as follows:

Microsoft (R) Visual C# Compiler version 4.3.0-dev (<developer build>)
Copyright (C) Microsoft Corporation. All rights reserved.

warning CS2023: Ignoring /noconfig option because it was specified in a response file
NOTE: Elapsed time may be less than analyzer execution time because analyzers can run concurrently.

Total analyzer execution time: 0.303 seconds.

Time (s)    %   Analyzer
   0.248   81   Microsoft.CodeAnalysis.CSharp.NetAnalyzers, Version=7.0.6.21701, Culture=neutral, PublicKeyToken=31bf3856ad364e35
   0.246   81      Microsoft.NetCore.CSharp.Analyzers.Runtime.CSharpDetectPreviewFeatureAnalyzer (CA2252)
   // trimmed output
  <0.001   <1      Microsoft.NetFramework.CSharp.Analyzers.CSharpSpecifyMessageBoxOptionsAnalyzer ()

   0.055   18   Microsoft.CodeAnalysis.NetAnalyzers, Version=7.0.6.21701, Culture=neutral, PublicKeyToken=31bf3856ad364e35
   0.034   11      Microsoft.NetCore.Analyzers.InteropServices.PlatformCompatibilityAnalyzer (CA1416)
   // trimmed output
  <0.001   <1      Microsoft.CodeQuality.Analyzers.ApiDesignGuidelines.TypeNamesShouldNotMatchNamespacesAnalyzer (CA1724)

Total generator execution time: 0.088 seconds.

Time (s)    %   Generators
   0.054   60   System.Text.Json.SourceGeneration, Version=7.0.6.22904, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51
   0.054   60      System.Text.Json.SourceGeneration.JsonSourceGenerator
   0.016   18   System.Text.RegularExpressions.Generator, Version=7.0.6.22904, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a
   0.016   18      System.Text.RegularExpressions.Generator.RegexGenerator

jaredpar · 2022-06-02T18:45:42Z

@dotnet/roslyn-compiler, @sharwell PTAL

jaredpar · 2022-06-02T18:46:11Z

Note: once this PR is merged I will be submitting a change to the binlog viewer to display this output in a similar fashion as we display analyzers

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs

jcouv

LGTM Thanks (iteration 1)

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs

sharwell · 2022-06-09T15:09:24Z

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs

@@ -1017,10 +1033,14 @@ private int RunCore(TextWriter consoleOutput, ErrorLogger? errorLogger, Cancella
 {
 // At this point we have a compilation with nothing yet computed. 
 // We pass it to the generators, which will realize any symbols they require. 
- compilation = RunGenerators(compilation, Arguments.ParseOptions, generators, analyzerConfigProvider, additionalTextFiles, diagnostics);
+ (compilation, var timingInfo) = RunGenerators(compilation, Arguments.ParseOptions, generators, analyzerConfigProvider, additionalTextFiles, Arguments.ReportAnalyzer, diagnostics);


⚠️ I do not believe we should alter the runtime behavior in response to ReportAnalyzer. Otherwise, we are required to let users known (in some cases) that the generators are slow because they tried to measure them.

One solution to slow generators is to enable the cache, but with this behavior it is impossible to validate.

I do not understand this comment. The only change here is that we enable the timing APIs which the user explicitly asked for.

The Arguments.ReportAnalyzer argument sets the value for disableCache, which fundamentally changes the performance characteristics of the generator as it applies to an incremental build. There is no way in the current design to understand or measure if the cache is providing a performance benefit. Decoupling the cache control from the ReportAnalyzer flag would improve the situation, because the user measuring performance would now be able to decide explicitly whether to measure performance with or without the cache (as a separate flag).

Thats' a fair point. At the same time I really feel like your second comment here should have been the first.

@chsienki doing this would require that GeneratorDriverState.With accept TrackIncrementalSteps as one of the values that can be overridden. Today it does not and have to assume there is a reason for that. Can it be safely changed in a cached driver or not?

I'm not sure I understand why you need to change it. From the looks of the PR it appears you're turning on TrackIncrementalGeneratorSteps in order to use the timing API but the two things are orthogonal.

The timing API is always available, and you will always get a result from driver.GetTimingInfo().

TrackIncrementalGeneratorSteps turns on the granular step tracking which allows a user to inspect the individual step timing as well as inputs and outputs, which populates extra fields inside the struct returned from driver.GetRunResult(). That is a perf hit, so it's always disabled in the compiler, and instead users can into it in unit tests if they want to assert things about the pipeline.

The timing API is always available, and you will always get a result from driver.GetTimingInfo().

Okay that is my misunderstanding then. I thought that the two were related. If they're orthogonal then this is much easier.

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs

sharwell · 2022-06-09T15:12:53Z

src/Compilers/Core/Portable/CommandLine/ReportAnalyzerUtil.cs

+ consoleOutput.WriteLine();
+ }
+
+ if (analyzerDriver is object)


💭 Seems like this is the odd man out

Suggested change

if (analyzerDriver is object)

if (analyzerDriver is { })

Would also be fine to change the three is { }/is object cases to is not null.

I remain confused why we prefer is { } to is object in our code base given that it's demonstrably inferior. It allows for us to insert silent true into our code base.

int i = 42; Console.WriteLine(i is {}); // silently converted to true Console.WriteLine(i is object); // Warn

What is the rationale behind preferring the pattern which allows more bugs into the codebase?

We generally prefer is not null. The is { } form is typically used instead of is var in cases where we want both type inference and a non-null check.

I only commented because this method originally had some use of is { } and some use of is object.

Seems like our existing IDE0150 analyzer (which converts x is object→x is not null) could be updated to handle x is { }.

sharwell

Overall seems fine. However, I'm not comfortable giving a ✅ if the /reportAnalyzer flag fundamentally changes the performance characteristics of the item being measured (which at the time of my review it did).

jaredpar · 2022-06-21T18:14:13Z

@chsienki, @sharwell PTAL

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs

jaredpar · 2022-06-22T00:36:35Z

Disabling auto-merge while we're in lockdown.

jcouv · 2022-06-27T17:05:43Z

/azp run

azure-pipelines · 2022-06-27T17:06:04Z

Azure Pipelines successfully started running 4 pipeline(s).

RikkiGibson · 2022-07-06T20:22:21Z

anything blocking this?

jaredpar · 2022-07-07T05:02:52Z

@RikkiGibson one remaining test failure I need to track down. Trying to find time to look into it.

This integrates the source generator timing work, dotnet#60267, into the `/reportAnalyzer` framework. A sample of the new output from a simple `net7.0` console app is as follows: ``` Microsoft (R) Visual C# Compiler version 4.3.0-dev (<developer build>) Copyright (C) Microsoft Corporation. All rights reserved. warning CS2023: Ignoring /noconfig option because it was specified in a response file NOTE: Elapsed time may be less than analyzer execution time because analyzers can run concurrently. Total analyzer execution time: 0.303 seconds. Time (s) % Analyzer 0.248 81 Microsoft.CodeAnalysis.CSharp.NetAnalyzers, Version=7.0.6.21701, Culture=neutral, PublicKeyToken=31bf3856ad364e35 0.246 81 Microsoft.NetCore.CSharp.Analyzers.Runtime.CSharpDetectPreviewFeatureAnalyzer (CA2252) // trimmed output <0.001 <1 Microsoft.NetFramework.CSharp.Analyzers.CSharpSpecifyMessageBoxOptionsAnalyzer () 0.055 18 Microsoft.CodeAnalysis.NetAnalyzers, Version=7.0.6.21701, Culture=neutral, PublicKeyToken=31bf3856ad364e35 0.034 11 Microsoft.NetCore.Analyzers.InteropServices.PlatformCompatibilityAnalyzer (CA1416) // trimmed output <0.001 <1 Microsoft.CodeQuality.Analyzers.ApiDesignGuidelines.TypeNamesShouldNotMatchNamespacesAnalyzer (CA1724) Total generator execution time: 0.088 seconds. Time (s) % Generators 0.054 60 System.Text.Json.SourceGeneration, Version=7.0.6.22904, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 0.054 60 System.Text.Json.SourceGeneration.JsonSourceGenerator 0.016 18 System.Text.RegularExpressions.Generator, Version=7.0.6.22904, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a 0.016 18 System.Text.RegularExpressions.Generator.RegexGenerator ```

The missing .projitems entries in the .shproj was causing solution explorer to not display the files in the shared projects. The SLN file changes are just VS reacting to the updates to the shared project files.

jaredpar · 2022-07-07T18:36:12Z

@RikkiGibson can u take a quick look at my latest commit? Had to make enough changes to test that I feel like I need a sign off on it.

RikkiGibson · 2022-07-07T19:04:59Z

src/Compilers/CSharp/Test/CommandLine/CommandLineTests.cs

@@ -9243,7 +9249,7 @@ public void SkipAnalyzersFlagFiltersAnalyzers()
 var srcFile = Temp.CreateFile().WriteAllText(@"class C {}");
 var srcDirectory = Path.GetDirectoryName(srcFile.Path);

- var args = new List<string>() { "/reportanalyzer", "/t:library", "/a:" + Assembly.GetExecutingAssembly().Location, srcFile.Path };
+ var args = new List<string>() { "/reportanalyzer", "/t:library", "/a:" + typeof(DoNothingGenerator).Assembly.Location, srcFile.Path };


Did you consider imitating 'AssemblyLoadingTestFixture' here: emit dlls to a temp folder using the compiler APIs, then give their paths here. The trouble here is that if we ever add more analyzers here, they will all be loaded here wherever the resources assembly is passed via '/analyzer'. It feels like it might be hard for it to scale, especially since they're essentially embedded into the existing resources project.

I considered it but emitting to disk add a large layer of complexity to the tests (also some maintenance issues). Most of our tests aren't interested in the act of round trippping to disk, they just want to verify that such and such analyzer has such and such behavior. Simpler to just grab in memory and use.

The trouble here is that if we ever add more analyzers here, they will all be loaded here wherever the resources assembly is passed via '/analyzer'.

Indeed that is true. Our existing tests suffer from this problem. In general I don't think we should be using that switch broadly to load our test anaylzers. Yes great for a number of cases but I think in general we should prefer specifying the analyzers we want to use for a given test vs. indirectly passing an assembly.

I considered it but emitting to disk add a large layer of complexity to the tests (also some maintenance issues). Most of our tests aren't interested in the act of round trippping to disk, they just want to verify that such and such analyzer has such and such behavior. Simpler to just grab in memory and use.

I feel like this means we haven't exposed the right helpers for this purpose.

Indeed that is true. Our existing tests suffer from this problem. In general I don't think we should be using that switch broadly to load our test anaylzers. Yes great for a number of cases but I think in general we should prefer specifying the analyzers we want to use for a given test vs. indirectly passing an assembly.

It's definitely more precise to test at the layer where you pass the exact types of analyzers in use. But it's still necessary to test at the layer where analyzer discovery is performed and it feels like existing tests shouldn't change incidentally because a new analyzer was needed for a new test. I feel that layer tends to be under-tested in part due to the difficulty of setting up the inputs to it.

All that said, I don't see a blocking need to change the way we obtain the analyzer here for this PR.

Roslyn recently updated their `/reportAnalyzer` support to include displaying source generator time in addition to analyzer time. This PR updates the structured logger viewer to display the newly added generator time in the same fashion that it displays anaylzer time Roslyn PR: dotnet/roslyn#61661

* upstream/main: (62 commits) Prevent assert from being hit (dotnet#62366) Don't offer '??=' for pointer types (dotnet#62476) Integrate generator times into /reportAnalyzer (dotnet#61661) Switch to a callback for cleaning up resources instead of passing in an explicit IDisposable. (dotnet#62373) Filter trees to only those containing global-usings or attributes prior to analyzing them. (dotnet#62444) Update PublishData.json Complete 'file' support for `SyntaxGenerator` (dotnet#62413) Apply changes directly to text buffer (dotnet#62337) Remove LangVer check from extended nameof binding (dotnet#62339) Fixed shared project file error (dotnet#62466) Handle new error codes Use MSBuid generated property for package path Exclude BCL libraries from Roslyn vsix Bump the integration test timeouts a bit Skip the balanced switch dispatch optimization for patterns on floating-point inputs (dotnet#62322) Test helpers shouldn't escape quotes by default (dotnet#62321) Reuse prior TableEntry values in the increment NodeTable builder if possible. (dotnet#62320) Install 3.1 runtime for SBOM tool Generate VS SBOM during official build. Minor refactoring in 'required' handling for override completion (dotnet#62422) ...

jaredpar added the Area-Compilers label Jun 2, 2022

jaredpar requested a review from a team as a code owner June 2, 2022 18:45

RikkiGibson self-assigned this Jun 7, 2022

jcouv self-assigned this Jun 8, 2022

jcouv reviewed Jun 8, 2022

View reviewed changes

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs Outdated Show resolved Hide resolved

jcouv reviewed Jun 8, 2022

View reviewed changes

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs Outdated Show resolved Hide resolved

jcouv approved these changes Jun 8, 2022

View reviewed changes

sharwell reviewed Jun 9, 2022

View reviewed changes

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs Outdated Show resolved Hide resolved

sharwell reviewed Jun 9, 2022

View reviewed changes

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs Outdated Show resolved Hide resolved

sharwell reviewed Jun 9, 2022

View reviewed changes

jaredpar force-pushed the rg branch from af0e292 to e268f82 Compare June 21, 2022 14:59

chsienki reviewed Jun 21, 2022

View reviewed changes

src/Compilers/Core/Portable/CommandLine/CommonCompiler.cs Outdated Show resolved Hide resolved

chsienki approved these changes Jun 21, 2022

View reviewed changes

jaredpar enabled auto-merge (squash) June 21, 2022 20:39

jaredpar disabled auto-merge June 22, 2022 00:36

jaredpar linked an issue Jun 24, 2022 that may be closed by this pull request

Binlogs / cmdline should include generator timing info #60347

Closed

sharwell approved these changes Jun 27, 2022

View reviewed changes

jaredpar added 3 commits July 7, 2022 09:20

PR feedback

0a5ff47

PR feedback

655fdb0

jaredpar added 4 commits July 7, 2022 09:20

PR feedback

d2c6c73

Test failure

4384f68

Fixed shared project file error

8265f12

The missing .projitems entries in the .shproj was causing solution explorer to not display the files in the shared projects. The SLN file changes are just VS reacting to the updates to the shared project files.

Fixup tests

9014fcf

jaredpar force-pushed the rg branch from b93c5fc to 9014fcf Compare July 7, 2022 18:35

RikkiGibson reviewed Jul 7, 2022

View reviewed changes

RikkiGibson approved these changes Jul 7, 2022

View reviewed changes

jaredpar enabled auto-merge (squash) July 7, 2022 20:11

jaredpar merged commit 867ffd9 into dotnet:main Jul 7, 2022

ghost added this to the Next milestone Jul 7, 2022

jaredpar deleted the rg branch July 7, 2022 21:05

jaredpar mentioned this pull request Jul 7, 2022

Include generator summary KirillOsenkov/MSBuildStructuredLog#610

Merged

allisonchou modified the milestones: Next, 17.4 P1 Jul 26, 2022

ryzngard mentioned this pull request Jul 27, 2022

Enable new inline rename by default #62992

Merged

Youssef1313 mentioned this pull request Sep 9, 2022

Feature request: Add generators execution times to /reportanalyzer #63887

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Integrate generator times into /reportAnalyzer #61661

Integrate generator times into /reportAnalyzer #61661

jaredpar commented Jun 2, 2022

jaredpar commented Jun 2, 2022

jaredpar commented Jun 2, 2022

jcouv left a comment

sharwell Jun 9, 2022

jaredpar Jun 21, 2022

sharwell Jun 21, 2022 •

edited

Loading

jaredpar Jun 21, 2022

jaredpar Jun 21, 2022

chsienki Jun 21, 2022

jaredpar Jun 21, 2022

sharwell Jun 9, 2022

jaredpar Jun 21, 2022

sharwell Jun 22, 2022 •

edited

Loading

sharwell Jun 22, 2022

sharwell left a comment

jaredpar commented Jun 21, 2022

jaredpar commented Jun 22, 2022

jcouv commented Jun 27, 2022

azure-pipelines bot commented Jun 27, 2022

RikkiGibson commented Jul 6, 2022

jaredpar commented Jul 7, 2022

jaredpar commented Jul 7, 2022

RikkiGibson Jul 7, 2022 •

edited

Loading

jaredpar Jul 7, 2022

RikkiGibson Jul 7, 2022

Integrate generator times into /reportAnalyzer #61661

Integrate generator times into /reportAnalyzer #61661

Conversation

jaredpar commented Jun 2, 2022

jaredpar commented Jun 2, 2022

jaredpar commented Jun 2, 2022

jcouv left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sharwell Jun 21, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sharwell Jun 22, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sharwell left a comment

Choose a reason for hiding this comment

jaredpar commented Jun 21, 2022

jaredpar commented Jun 22, 2022

jcouv commented Jun 27, 2022

azure-pipelines bot commented Jun 27, 2022

RikkiGibson commented Jul 6, 2022

jaredpar commented Jul 7, 2022

jaredpar commented Jul 7, 2022

RikkiGibson Jul 7, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sharwell Jun 21, 2022 •

edited

Loading

sharwell Jun 22, 2022 •

edited

Loading

RikkiGibson Jul 7, 2022 •

edited

Loading