roslyn: Performance: Basic Keypresses in Solution with All Analyzers Disabled Causes `ServiceHub.RoslynCodeAnalysisService.exe` to Utilize ~10% of CPU

I wanted to briefly check in with this issue as there has been continuing development and exploration on what the heck is happening here.

First off, I wanted to share my appreciation for this thread and its discussion. I know it got messy, and while I didn’t appreciate @PathogenDavid’s sharp feedback at the time, in hindsight he was right: I sort of stepped in it here.

(hey, I had just got back from some time off at the time and was not exactly in GitHub Battle Mode shape 😅)

But, that’s ok, I learned a lot. And I am still learning. I appreciate your patience while I climb onto the same level as you all. As I hope to demonstrate below, there are a lot of pieces here.

And hey, if we ultimately find a gremlin (or two) that is degrading performance of your product, then worth it, right?

OK, so… getting back to the original heart of the thread, which was that a source generator (Refit) seemed to be going crazy, and it may or may not be due to ServiceHub.RoslynCodeAnalysisService.exe. I have upgraded to Visual Studio 2022 Preview 3.1 with the .NET6 SDK RC1 bits, with my solution upgraded to net6.0.

Sure enough, after some time (many hours) of development, I noticed that my CPU was getting a little more active than I expected and had even noticed earlier during that same development session. So, I took a peek with dotTrace. Here is what I saw:

Indeed, it sure seems like Refit is having a, uh, fit. 😁 But, looking closely, now that we are in net6.0, you can see that JsonSourceGenerator is also present in the CPU time as well. In fact, there’s also a LoggerMessageGenerator in for the ride, with the top 3 call trees being ascribed to source generators.

Well, on a hunch, I closed my SLN and opened a new Visual Studio 2022 process. This is what I saw with that same activity as performed above in the new IDE session:

Notice the difference? Everything looks super clean and expected when opening with the brand new Visual Studio 2022 process, with none of the source generators taking nearly any of the time of the previous first grab.

So it would seem that much like this issue, there is something funny happening with the ServiceHub.RoslynCodeAnalysisService.exe process over time (or is simply triggered by as of yet-unknown process) that seems to degrade its performance and thusly impacts all source generators (not just Refit).

This has been reported here for your review: https://developercommunity.visualstudio.com/t/Roslyn-Degrades-over-Time-Placing-Press/1508373

How does this happen and how do I avoid this from happening in the future?

It can be caused by many different things. In this case, the problems may have been exacerbated by having two copies of Visual Studio open together (both with a solution open), plus two copies of Timeline64 running. The easiest way to reduce the profiling load is to close unrelated “busy” applications prior to profiling.

During my own work, I find it tedious to close applications, so I tend to instead launch the profiler manually using a bunch of modified settings (mostly this General Purpose scenario but with greatly increased buffer sizes). I also have a large amount of memory and extremely fast storage so it makes it a bit easier to get away with sub-optimal measurement conditions. 😃

I am almost wanting to start attaching dotTrace/dotMemory

This tends to cause problems. The presentation is different than we’re used to seeing, so problems tend to get lost in the details. It also doesn’t data we rely on from the feedback tool for accuracy. The workflow and automation are built entirely around the primary expected data, and even small deviations can mean the difference between getting a fix and getting Closed - Lower Priority.

@Mike-E-angelo note that a change was just merged to Refit (https://github.com/reactiveui/refit/pull/1216) that should correct the CPU overhead when used from Visual Studio 2022.

Haha sorry we will never agree that over 50% of the CPU

I’m sorry, but i don’t think we’re going to change in that regard. Frankly, i would prefer we get up to 100% (albeit with a low pri process such that other interactive tasks on the system are unimpacted). We have multicore machines and facilitating getting results back to the user as quickly as possible is a key design goal here. Limiting our usage to some arbitrary low percentage doesn’t seem sensible**

10% with such a resource is not a good thing,

I genuinely do not understand the argument there 😃. Percentage isn’t something that matters. After all, the more concurrent and decoupled we make things, the easier it will be for us to just hit 100% as we scale up. What matters is total aggregate CPU usage and if that is out of line for a particular feature (or set of features).

–

** One area where it would make sense is battery operated devices where longevity of unplugged time is a valued resource. However, for normal desktop usage this would not apply.

right. i’m saying: we’d need traces without hte SG running to see if there is anything amiss here, or if this is just normal and expected behavior. Thanks!

At the very least it seems incongruent to allow analyzers to be disabled but not source generators,

Analyzers are a strictly additive thing. They do not impact the meaning of code or the ability for it to be compiled. SourceGenerators are a required thing. Without them you legitimately may not have hte code needed for things to even be semantically understandable.

Even when all analyzers are disabled on the solution?

Source generators aren’t analyzers, so i don’t think disabling analyzers would affect them. @chsienki for confirmation though.

Looks like most of the time is spent here and here.

I’m confused why this these would be prominent in your trace. Especially the second one which is commented // internal for testing.

I’m curious about what’s happening in this scenario so I will try to make some time to check out the trace as well. I’ll let you know if I spot anything worth calling out in it.

@dotnet/roslyn-compiler two seconds in GetTypeByMetadataName does seem on the high side. What information would be helpful to diagnose if somethign is going wrong here?