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

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

Closed
danroth27 opened this issue Mar 2, 2023 · 46 comments
Closed
Assignees
Labels
area-compiler Umbrella for all compiler issues
Milestone

Comments

@danroth27
Copy link
Member

danroth27 commented Mar 2, 2023

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%.

image

Lots of GC wait in :ServiceHub.RoslynCodeAnalysisService`:

image


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)

@ghost ghost added the untriaged label Mar 2, 2023
@Mike-E-angelo
Copy link

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:
#5697 (comment)

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
Copy link
Member Author

@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.

@phil-allen-msft phil-allen-msft added the area-compiler Umbrella for all compiler issues label Mar 2, 2023
@Mike-E-angelo
Copy link

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

@chsienki chsienki added this to the Backlog milestone Apr 27, 2023
@ghost ghost removed the untriaged label Apr 27, 2023
@Mike-E-angelo
Copy link

How it's goin'...

@Mike-E-angelo
Copy link

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

@CyrusNajmabadi
Copy link
Member

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

@Mike-E-angelo
Copy link

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
Copy link
Member

@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
Copy link

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
Copy link
Member

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
Copy link
Member

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
Copy link

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
Copy link
Member

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

image

and

image

On the exclusive side, the big hits are:

image

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

@CyrusNajmabadi
Copy link
Member

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

image

image

I believe this is being looked at as we speak.

@Mike-E-angelo
Copy link

Mike-E-angelo commented Aug 22, 2023

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
Copy link

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
Copy link
Member

@Mike-E-angelo see update at: #8371 (comment)

@DustinCampbell
Copy link
Member

DustinCampbell commented Aug 28, 2023

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

@Mike-E-angelo
Copy link

@Mike-E-angelo see update at: #8371 (comment)

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
Copy link

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
Copy link
Member

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

@Mike-E-angelo
Copy link

image

Looking forward to it @CyrusNajmabadi, thank you.

@DustinCampbell
Copy link
Member

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?

#9214

@Mike-E-angelo
Copy link

Mike-E-angelo commented Oct 11, 2023

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
Copy link
Member

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

@Mike-E-angelo
Copy link

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 DustinCampbell self-assigned this Oct 11, 2023
@DustinCampbell
Copy link
Member

@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?

image

If so, what happens if you check them?

@Mike-E-angelo
Copy link

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
Copy link
Member

FWIW, #9367 should improve the experience when those boxes are unchecked.

@DustinCampbell
Copy link
Member

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

@Mike-E-angelo
Copy link

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, #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
Copy link
Member

DustinCampbell commented Oct 11, 2023

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. 😄

@Mike-E-angelo
Copy link

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
Copy link
Member

@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
Copy link

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
Copy link
Member

@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
Copy link

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
Copy link
Member

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
Copy link

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

@DustinCampbell
Copy link
Member

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

@ryzngard
Copy link
Contributor

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
Copy link

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
Copy link
Member

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
Copy link

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!

@Mike-E-angelo
Copy link

Hey all, I made mention of this issue on the twitters today and noticed it was still open. A kind reminder here that you can close it as I have not seen this issue or anything like it from Visual Studio for a very long time now. Of course, if there is a reason you want to keep it open that is OK too. :)

Thank you all again for the incredible work you are doing, it is greatly appreciated and valued. 🙏🙏🙏

https://x.com/Mike_E_angelo/status/1837123212762546497

@DustinCampbell
Copy link
Member

Thanks for your kind words @Mike-E-angelo!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-compiler Umbrella for all compiler issues
Projects
None yet
Development

No branches or pull requests

8 participants