Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bad performance in CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer with System.Text.Json source generator #74761

Closed
mus65 opened this issue Aug 14, 2024 · 12 comments · Fixed by #74762
Labels
Area-Analyzers Bug Resolution-Duplicate The described behavior is tracked in another issue
Milestone

Comments

@mus65
Copy link

mus65 commented Aug 14, 2024

We were trying to make use of System.Text.Json source generation with a class that is pretty deeply nested with a lot of classes and properties.

We noticed that this causes a huge slowdown in build performance. While a build previously took about 5s, the source generation caused it go up to about 40s.

It seems like the generated code by System.Text.Json causes some kind of performance issue in CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer . I created a repro below with 1000 classes, resulting in 1000 source generated files by System.Text.Json.

Is there a way to disable this particular analyzer? Disabling IDE0005 in .editorconfig seems to have no effect. The only way we found to avoid this, is by disabling EnforceCodeStyleInBuild completely.

I'm also wondering why the analyzer even analyses source generated code. Is this expected behaviour? Or is this actually not what is happening?

Version Used:

.NET 9 Preview 7. Also reproducible with .NET 8 .

Steps to Reproduce:

  1. git clone https://github.com/mus65/roslyn-stj-sourcegen-repro
  2. run dotnet build -v diag | grep -B 4 -A 2 CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer . This outputs the following on my local machine:
NOTE: Elapsed time may be less than analyzer execution time because analyzers can run concurrently. (TaskId:112)
                     Total analyzer execution time: 70.182 seconds. (TaskId:112)
                     Time (s)    %   Analyzer (TaskId:112)
                     69.104   98   Microsoft.CodeAnalysis.CSharp.CodeStyle, Version=4.12.10.37901, Culture=neutral, PublicKeyToken=31bf3856ad364e35 (TaskId:112)
                     68.389   97      Microsoft.CodeAnalysis.CSharp.RemoveUnnecessaryImports.CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer (EnableGenerateDocumentationFile, IDE0005, IDE0005_gen, RemoveUnnecessaryImportsFixable) (TaskId:112)
                     0.350   <1      Microsoft.CodeAnalysis.CSharp.UseExpressionBody.UseExpressionBodyDiagnosticAnalyzer (IDE0021, IDE0022, IDE0023, IDE0024, IDE0025, IDE0026, IDE0027, IDE0061) (TaskId:112)
                     0.301   <1      Microsoft.CodeAnalysis.CSharp.RemoveUnusedParametersAndValues.CSharpRemoveUnusedParametersAndValuesDiagnosticAnalyzer (IDE0058, IDE0059, IDE0060) (TaskId:112)

Diagnostic Id:

IDE0005: Remove unnecessary using directives

Expected Behavior:

Minimal to no impact on build performance.

Actual Behavior:

A lot of CPU time wasted in CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer:

@dotnet-issue-labeler dotnet-issue-labeler bot added Area-Analyzers untriaged Issues and PRs which have not yet been triaged by a lead labels Aug 14, 2024
@CyrusNajmabadi
Copy link
Member

  1. This takes a long time, because it's requesting diagnostics (as this feature is driven by the diagnostics emitted by teh compiler).
  2. That said, it's unclear why we are running this on generated code. @sharwell any reason youc an think of to not disable this in generated code scenarios?
  3. @sharwell do you know why supressing IDE0005 is having no effect here?

@CyrusNajmabadi
Copy link
Member

Note: this is set to:

    protected override GeneratedCodeAnalysisFlags GeneratedCodeAnalysisFlags => GeneratedCodeAnalysisFlags.Analyze | GeneratedCodeAnalysisFlags.ReportDiagnostics;

But it's unclear why. That code was added in b3476d1#diff-3c62b8ef897e66c9ff76350001c3df5de9dbb9913d8369056dedb9c7404cc8caL71

But what's odd is that the code before this point didn't seem to be asking about generated code. The only feature that did was src/Analyzers/Core/Analyzers/MakeFieldReadonly/MakeFieldReadonlyDiagnosticAnalyzer.cs

So i don't know why unnecessary usings analysis was opted into that at this point. @Youssef1313 you made the change in this PR: #62895

I'm gonig to disable this for now to see what breaks.

@Youssef1313
Copy link
Member

@CyrusNajmabadi It was existing but just refactored

image

I think the reason may be that the analyzer should still fade out unnecessary usings in IDE. There was changes around it in #29704 (yet, it was still analyzing generated code even before that PR)

@Youssef1313
Copy link
Member

As this is very specific to IDE, I think we shouldn't incur the performance penalty for command-line builds. But I don't know if there is currently a way to do it

@Youssef1313
Copy link
Member

Youssef1313 commented Aug 14, 2024

3. @sharwell do you know why supressing IDE0005 is having no effect here?

I reported this before and was supposed to be fixed by #73263

@CyrusNajmabadi
Copy link
Member

I think the reason may be that the analyzer should still fade out unnecessary usings in IDE

I'm very ok with this not working

@sharwell
Copy link
Member

Duplicate of #72162

@sharwell sharwell marked this as a duplicate of #72162 Aug 15, 2024
@sharwell sharwell closed this as not planned Won't fix, can't repro, duplicate, stale Aug 15, 2024
@sharwell sharwell added the Resolution-Duplicate The described behavior is tracked in another issue label Aug 15, 2024
@mus65
Copy link
Author

mus65 commented Aug 15, 2024

@sharwell how is this a duplicate of #72162 ? It has been fixed since April, but this is reproducible with the latest .NET 9 preview.

@sharwell
Copy link
Member

sharwell commented Aug 16, 2024

@mus65 if you add the following line to a source file, what version is printed when you build?

#error version

It's marked as a duplicate primarily because we found the report to be a red herring. Due to some design limitations, the compiler was reporting performance overhead as part of CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer when in fact that overhead was unavoidable. When the analyzer is disabled, the same work occurs, just not as part of that analyzer. Therefore, the analyzer itself is not what is responsible for the overhead. This is a rare occurrence across analyzers in general, but known to occur for this specific case.

Based on the report above and the contents of the linked repo, it is my belief that the fix for the way performance data is reported from #72162 is not included in the SDK you were using in the repro case. This can be verified by getting the exact version information.

@mus65
Copy link
Author

mus65 commented Aug 16, 2024

@sharwell

Compiler version (.NET 9 Preview 7):

Compiler version: '4.12.0-1.24379.1 (b2a6fc8e)'. Language version: 13.0.

Due to some design limitations, the compiler was reporting performance overhead as part of CSharpRemoveUnnecessaryImportsDiagnosticAnalyzer when in fact that overhead was unavoidable. When the analyzer is disabled, the same work occurs, just not as part of that analyzer.

But then why is compilation a lot faster when changing EnforceCodeStyleInBuild to false? In my repro, it's set to true in the csproj and when setting it to false time goes down from about 15s to about 9s. In our actual production case, the difference is even bigger (4s -> 25s).

@sharwell
Copy link
Member

@mus65 Thank you, I'm able to reproduce some issues with this information and will work to get those corrected.

@sharwell sharwell reopened this Aug 16, 2024
@sharwell
Copy link
Member

sharwell commented Aug 16, 2024

Issues to fix:

  • Diagnostics gathering is slightly slower with this analyzer enabled (will run differential analysis to try and determine the cause).

  • The analyzer is not disabled by default because one of the diagnostics it reports has default severity 'Warning'. This is generally fine, but we need to return early from the analyzer implementation based on the MinimumReportedSeverity.

    Use more specific checks for skipping work for unused usings #74807

sharwell added a commit to sharwell/roslyn that referenced this issue Aug 19, 2024
This change ensures AnalyzeSemanticModel only performs analysis when
unused imports are being reported. Previously, this method would run
when the only enabled diagnostic was 'EnableGenerateDocumentationFile',
even though that diagnostic is unrelated to the work performed in
AnalyzeSemanticModel.

Discovered during investigation of dotnet#74761.
@arunchndr arunchndr added Bug and removed Area-Analyzers untriaged Issues and PRs which have not yet been triaged by a lead labels Nov 6, 2024
@arunchndr arunchndr added this to the Backlog milestone Nov 6, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area-Analyzers Bug Resolution-Duplicate The described behavior is tracked in another issue
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants