Simple Keypresses in Razor File Takes 10-20% CPU for nearly 25 Seconds

[danroth27]

This issue has been moved manually from a ticket on Developer Community.

---

From @mike-e-angelo

Please see attached. I am seeing higher CPU utilization as expected/usual with simple keypresses in a Razor file. usually it takes about 6 seconds to die down and here it’s taking nearly half a minute, with the CPU oscillating between 10-20%.

Lots of GC wait in :ServiceHub.RoslynCodeAnalysisService`:

---

Original Comments

@mike-e-angelo on 10/16/2022

Here’s a recording after restarting Visual Studio. CPU spikes at 15% and churns for “only” 18 seconds. IMO that is still incredibly excessive but better than the condition captured in the original ticket.

@jaredpar on 10/28/2022:

@333fred @DustinCampbell recent update

Took a quick look at the speedometer results from my test revert. That was not the regression cause, reverting actually worsened the impact (which is good in some ways, I suppose). My current understanding of the bug is that something in the checkin is causing the IDE's caches to be blown more frequently, so we need to scrutinize our history for things that could either cause the generator to run more frequently, or that should shorten the lifetime of RazorCodeDocuments (the tooling has a cache keyed on weak references to RazorCodeDocuments, so if we shortened the lifetime of something it could cause the cache entry to be invalidated)

[Mike-E-angelo]

Thank you very much for your time and investigation into this matter, @danroth27 & team. 🙏 FWIW I have included an earlier version of my codebase attached to this ticket: https://developercommunity.visualstudio.com/t/Upgrade-to-EFCore-7-Results-in-Unexpecte/10231883

I have also provided instructions here on a previous iteration of this issue that easily and consistently seems to do a good job of consistently making Razor tooling grumpy: https://github.com/dotnet/razor/issues/5697#issue-1045241564

It would be very much appreciated to know that this is being incorporated into your test processes in some way. As #5697 shows, I have been reporting this type of issue for over two years now (at least), each time being told that it has been addressed, only to find that it has manifested in another way (as this ticket clearly demonstrates).

It would seem that after an issue is marked as resolved, the code that I have provided would be used to verify the fix, and -- more importantly -- to verify that another issue was not introduced. As you can see, this issue was reported in October and it is only now being properly recorded. That is a painful five-month window, especially when one is working under the impression that a previous issue has been addressed.

Thank you for your consideration.

[danroth27]

@Mike-E-angelo Thank you for your patience and diligence in working with us on these performance issues!

Yes, we still have all of the data you shared with us on the original feedback ticket. Having these real world projects really helps us with testing and ongoing validation.

Please note that just because an issue hasn't been moved to GitHub that doesn't necessarily mean it isn't being looked into. In some cases it's easier to track issues using the VS feedback system, especially when private customer data is including in the issue report.

It looks like several of the issues you are hitting are related to the problems with have with tag helper discovery (which is used for Blazor component discovery). This is a pretty fundamental issue with how the Razor compiler works and is an area of focused investment and attention. Unfortunately, there really isn't a quick fix for some of these issues. But we are working on it.

[Mike-E-angelo]

Thank you very much for your reply, @danroth27. I very much appreciated that and it made my day. 👍🙏

[Mike-E-angelo]

How it's goin'...

[Mike-E-angelo]

Thank you for any update that you can provide on this issue.

[CyrusNajmabadi]

@Mike-E-angelo please provide traces with your report. Thanks!

[Mike-E-angelo]

Hi @CyrusNajmabadi please note that I did that with the original ticket on developercommunity. I have about a dozen of them already reported under this type of issue, but this one in particular was moved to this issue on GitHub.

[CyrusNajmabadi]

@Mike-E-angelo many fixes have gone in since then. Please file updated traces (against latest public preview) so we can see what the hot spots are now. Thanks.

[Mike-E-angelo]

This is the first I have heard of this, @CyrusNajmabadi. How often should I be doing this on confirmed and open issues such as this one? Am I to open a new issue each time on developercommunity as the previous one was closed in favor of this one?

[CyrusNajmabadi]

How often should I be doing this on confirmed and open issues such as this one?

Whenever queried. We'd need to see what the hot spots are now. Thanks!

[CyrusNajmabadi]

Am I to open a new issue each time on developercommunity as the previous one was closed in favor of this one?

The issues aren't the relevant bit here. The traces are. Submitting up to date traces on he latest public previews will help ensure that efforts are being focused on the right areas. Thanks!

[Mike-E-angelo]

Here you are @CyrusNajmabadi -- https://developercommunity.visualstudio.com/t/Simple-Keypresses-in-Razor-File-Takes-10/10446972?port=1025&fsid=b23bed29-27d0-4950-9b8d-93e802e5b8e9

It took nearly 90 seconds for basic keypresses to be processed and for the CPU to idle down.

[CyrusNajmabadi]

Razor guys, looks like the majority of time is in:

and

On the exclusive side, the big hits are:

Which makes it seem as if GC is actually the concern here. So potentially something is churning out garbage? Investigating more.

[CyrusNajmabadi]

Yup. On the memory side, there's large amount of json production:

I believe this is being looked at as we speak.

[Mike-E-angelo]

Worth also noting that the churn is now in the 60-90 second range, and the CPU levels oscillate between 30-70% in addition to the 10-20% area. This is up from the original report of last October which was 10-20% for 25 seconds.

[Mike-E-angelo]

Submitting up to date traces on he latest public previews will help ensure that efforts are being focused on the right areas

Thank you for any update you can provide on this issue, reported October 16, 2022.

[CyrusNajmabadi]

@Mike-E-angelo see update at: https://github.com/dotnet/razor/issues/8371#issuecomment-1688553822

[DustinCampbell]

FWIW, I'm working on finishing up my message pack work this week, which should eliminate the JSON production.

[Mike-E-angelo]

@Mike-E-angelo see update at: https://github.com/dotnet/razor/issues/8371#issuecomment-1688553822

Thank you for that @CyrusNajmabadi but from what I can tell this was simply confirming what was already reported last October, if only demonstrating it has gotten way worse since then.

FWIW, I'm working on finishing up my message pack work this week, which should eliminate the JSON production.

Thank you for the update and for your efforts @DustinCampbell, they are greatly appreciated. I am thinking that the overwhelming amount of JSON transfer + de/serialization is indeed what is contributing to this issue. Do you happen to have a PR/issue for this that we can track for further information?

[Mike-E-angelo]

Thank you for any update you can provide on this issue. 🙏

This issue is now being tracked by my semi-weekly standups in the Friction Points, where I discuss points of friction encountered in building a startup on Microsoft technology: https://youtu.be/vmqPNZHDmVI?si=rp8W6AvJqRDmMpFN&t=601

[CyrusNajmabadi]

@Mike-E-angelo we update issues when there is new information. Thanks.

[Mike-E-angelo]

Looking forward to it @CyrusNajmabadi, thank you.

[DustinCampbell]

Thank you for the update and for your efforts @DustinCampbell, they are greatly appreciated. I am thinking that the overwhelming amount of JSON transfer + de/serialization is indeed what is contributing to this issue. Do you happen to have a PR/issue for this that we can track for further information?

https://github.com/dotnet/razor/pull/9214

[Mike-E-angelo]

Unfortunately, #9214 does not seem to improve this issue and this issue actually seems to have become worse w/ Preview 3. Whereas I counted 90 seconds of CPU utilization before, I now count over 100 seconds of CPU utilization in the recorded session here with a simple keypress: https://developercommunity.visualstudio.com/t/Simple-Keypresses-in-Razor-File-Takes-10/10489359

[DustinCampbell]

I'm not disputing that the issue is worse in 17.8p3, but I think it's highly unlikely that #9214 is the culprit. :smile:

[Mike-E-angelo]

Fair enough @DustinCampbell I have rewritten the sentence to make it more aligned with my intended statement.

I was eyeballing it with my measurements and do not believe I used the same file the last time, so there are factors of possible variance here. 👍 In fact it may be whatever #9395 (or other) has brought to the table. 😬

[DustinCampbell]

@Mike-E-angelo: Looking at the traces you just provided, I'm surprised to not see a ServiceHub.RoslynCodeAnalysisService.exe process. So, all Razor processing that was improved by #9214 is happening in devenv.exe. Out of curiosity, do your settings disable running Roslyn code analysis in a separate process? In other words, do you have these options unchecked?

If so, what happens if you check them?

[Mike-E-angelo]

Thank you for that pointer @DustinCampbell. For further context here, I have been reporting performance issues like these with the Roslyn team for several years now I want to say. One of the issues I reported in February suggested that I uncheck Run code analysis in separate process: https://developercommunity.visualstudio.com/t/Perpetual-30-CPU-Utilization-in-Servic/10267489

So it was unchecked. I checked it, restarted, and provided a new recording for you on the developercommunity ticket.

It seems better, but I cannot compare this apples-to-apples as I did not have this checked when I reported this in March.

Instead of 90-100 seconds CPU utilization, I am seeing about 60-70 seconds now. The findings are in the developercommunity ticket. Please let me know if any further information is required and I will assist.

[DustinCampbell]

FWIW, https://github.com/dotnet/razor/pull/9367 should improve the experience when those boxes are unchecked.

[DustinCampbell]

Actually, looking at your new traces, it seems that there's be wins when those boxes are checked as well.

[Mike-E-angelo]

it seems that there's be wins when those boxes are checked as well.

Indeed @DustinCampbell it seems it's about 30% better now. It's something to build on. :) Thank you again for your efforts.

FWIW, https://github.com/dotnet/razor/pull/9367 should improve the experience when those boxes are unchecked.

Can you please verify the preferred settings here for Razor development? The one aspect that is different for me now is that I upgraded my RAM and have 64GB dedicated to my development VM. This has improved other issues that I was experiencing with constant paging and subsequent deadlocks. I think I am able to stretch the legs out a bit with other configurations as well.

[DustinCampbell]

I would say that recommended options are to leave the code analysis options at their defaults unless there's a very good reason to change them. Essentially, there's pros and cons, and some scenarios can yield better results when code analysis runs in-proc at the cost of degrading other scenarios. So, changing the defaults can be a bit... 🤷. Work that happens out-of-proc can run on .NET Core, which generally performs better. I should also mention that having JetBrains in the mix means that lots of similar work is happening between the two systems, which can really be a challenge on super-large solutions. So, even if we're able to get things extremely efficient on the Razor-side, there's no guarantee it'll get to a place that's acceptable. Currently, we have a lot of work to do yet, so I don't want to point fingers in another direction just yet. :smile:

[Mike-E-angelo]

OK @DustinCampbell I will keep those both checked then as I understand that to be default settings. 👍

I should also mention that having JetBrains in the mix means that lots of similar work is happening between the two systems, which can really be a challenge on super-large solutions.

Believe me, I understand, and JB/R# has given me zero problems until introducing Razor. Its C# experience is lightning-fast with zero problems and responds as fast as I would expect.

Ever since getting into Blazor Server-side, however, my life has been one huge grief factory with both JB and Visual Studio. I must have reported at least 100+ issues in each camp, all related in some way to the Razor engine. It's really impressive to see both organizations really struggle with this for as long as they each have with it. I do not think I have seen anything like this in my roughly 22 years of .NET development experience. I can say with certainty that I never experienced so much development friction with either Silverlight or WPF, which is where I have spent the majority of my career and wrote a lot of code.

FWIW, you may be interested to know that JB solves its processing for the same keystrokes in a Razor file ~30 seconds at present. This is nearly ~15 seconds faster than Visual Studio 17.8 Preview 3. It does take higher utilization up front though, which is ... ok? 🤔

[sharwell]

@Mike-E-angelo I continue to keep those boxes unchecked on my own machine as I find it offers improved overall performance. The differential traces you provided (one with, and one without the checked boxes) highlighted an unintentional issue which penalized in-process performance. Once that issue is resolved, the relative performance of them should again invert.

We have definite long-term goals for the two-process execution model to offer the same level of user-observed performance as single-process execution, but there are cases where I continue to see differences. I don't believe that lower total CPU usage (the sum of all processes involved) is a goal of this, and I wouldn't expect to see that achieved except in cases where one of the processes has been unfairly penalized (the penalties are never intentional, but sometimes occur).

[Mike-E-angelo]

Thank you for the guidance @sharwell but unfortunately, I am now confused. 😅 In particular, I am interested in why you operate with both unchecked. This seems to imply that you are not using the latest .NET which has all the performance improvements. I am having a difficult time reconciling how this would be faster.

[DustinCampbell]

@sharwell: Is this official guidance from Roslyn in general? If so, is there an effort to remove Roslyn OOP? If not, why?

[Mike-E-angelo]

I wanted to check in with this issue to see if any further attempts will be made to address it, or at least make it on par with JB's performance. 🤔

[DustinCampbell]

We have a few more changes that have gone into that might make things better, but those changes are currently slated for 17.9.

[Mike-E-angelo]

That works for me @DustinCampbell thank you for taking the time to update. 🙏

[DustinCampbell]

Absolutely. Thank you for continuing to provide traces and information. It's extremely helpful!

[ryzngard]

https://devdiv.visualstudio.com/DevDiv/_workitems/edit/1759401 is another report. I noticed a good chunk of the CPU utilization is in completion+design time generation.

Perf traces attached to the ticket.

[Mike-E-angelo]

I am glad to see that I am not the only person seriously using your product. 🤪 I get worried at times. 😁

🦃 Happy Holidays to the team out there. 🙏

[DustinCampbell]

https://devdiv.visualstudio.com/DevDiv/_workitems/edit/1759401 is another report. I noticed a good chunk of the CPU utilization is in completion+design time generation.

Perf traces attached to the ticket.

Yeah, it seems like we're doing a lot more work (i.e. parsing files) than we used to. I'm looking at reducing allocations in the parsing and code gen. However, we should probably understand why we're doing more parsing and code gen than before.

[Mike-E-angelo]

Wow it appears that this issue is fixed! 🤯🤯🤯

(not sure why it's saying it's not responding, it is :))

5-8% CPU utilization for only several seconds! 🤯🤯🤯🙏🙏🙏💖💖💖

Thank you so very much out there for all your efforts. I was not able to notice this recently as my past month or so has been in learning Bicep and essentially re-designing our Azure deployments. This is really good news. Thank you!