dotnet / project-system

The .NET Project System for Visual Studio
MIT License
969 stars 387 forks source link

Enormous memory and CPU consumption by SDK project style #4078

Closed evgeny-burmakov closed 4 years ago

evgeny-burmakov commented 6 years ago

After migrating from classic project structure to SDK style on large solution we are met with enormous memory consumption by VisualStudio and performance degradation (mainly on starting phase but quite long time). Also VS crashes with OutOfMemoryException time to time when project files are actively modified. Memory consumption increased from 1.2Gb on classic style to 2.3Gb on SDK style.

Environment:

4creators commented 6 years ago

Can confirm for both C# projects (new style and old style) and vcxproj. Every time solution size approaches 60 - 80 projects limit project handling becomes extremely slow and fragile. Problems observed by me could be of different nature though as they exists for both new and old csproj and additionally manifest with vcxproj (in this case project configuration changes are extremely slow and consume up to 2.5 GB memory).

drewnoakes commented 6 years ago

@evgeny-burmakov thanks for the report. We recognise the need to reduce memory for SDK projects and are actively working to improve this.

It would be very helpful if you could report an issue in VS itself and include recorded data. We can then determine whether your situation is one we're aware of, or something new. You can do this via Help | Feedback | Report a problem. Report a new issue, enter the title/description and press next. On the Attachments page, click Record and record a trace from a new instance of VS. The trace has a maximum duration of 30 seconds, so please do whatever triggers the rise in memory usage during a 30 second period then submit the recording. You will receive an email with a link to the submission which you can post here. We can then follow up. The whole process should only take a few minutes and gives us enough information to help your situation directly.

drewnoakes commented 6 years ago

For more information on submitting a report, see https://docs.microsoft.com/en-us/visualstudio/ide/how-to-report-a-problem-with-visual-studio-2017?view=vs-2017

evgeny-burmakov commented 6 years ago

I have collected the report. Not sure that it is enough for analysis. The loading phase is quite big and definitely won't fit into 30 seconds. Let me know if dump should be regenerated and which stage is more important for recording. Also I have noticed that "Live code analysis" take a lot time, memory and CPU on loading phase even if isn't any opened file.

https://developercommunity.visualstudio.com/content/problem/350638/enormous-memory-and-cpu-consumption-by-sdk-project.html

jmarolf commented 6 years ago

Internal report here

jmarolf commented 6 years ago

looking at the gc heap, ~50% of memory is due to resharper. Doesn't mean we can't do better (the other 20% is string allocation) but disabling resharper should get better performance in the short term.

jmarolf commented 6 years ago

Filtering out the resharper symbols from the memory dump, these are the top contributors from the project system

Name Count Size (Bytes) Inclusive Size(Bytes) Total
Microsoft.VisualStudio.ProjectSystem.VS.Implementation.Package.OuterProjectNode 176 87,240 57,134,124 15,354,240.00
Microsoft.VisualStudio.ProjectSystem.UnconfiguredProjectImpl 176 178,148 56,995,488 31,354,048.00
Microsoft.VisualStudio.ProjectSystem.ProjectCapabilitiesScope 791 131,900 56,927,084 104,332,900.00
Microsoft.VisualStudio.ProjectSystem.VS.Implementation.Package.ProjectNode 176 148,132 35,420,872 26,071,232.00
Microsoft.VisualStudio.ProjectSystem.VS.Implementation.Package.ProjectConfigProvider 176 10,560 29,654,744 1,858,560.00
Microsoft.VisualStudio.ProjectSystem.VS.Implementation.Package.TreeService 176 32,900 15,854,188 5,790,400.00
Microsoft.VisualStudio.ProjectSystem.Build.ProjectEvaluationMessageLogger 262 12,576 15,632,092 3,294,912.00
Microsoft.VisualStudio.ProjectSystem.VS.Implementation.Package.ProjectNode+ProjectNodeActiveConfigurationHelper 176 183,840 11,519,768 32,355,840.00
Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.DependenciesProjectTreeProvider 176 33,316 10,817,996 5,863,616.00
Microsoft.VisualStudio.ProjectSystem.VS.Implementation.Package.SingleFileGenerators 176 18,304 10,800,092 3,221,504.00
Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.Subscriptions.DependencySubscriptionsHost 176 35,200 7,254,624 6,195,200.00
Pilchie commented 6 years ago

@jmarolf what did you have fold and group settings for in that?

jmarolf commented 6 years ago

@Pilchie believe it or not I opened the *.dmp file in VS. This is looking at the raw object in memory not objects that were in the gc heap. I'll amend the comment to be more clear.

evgeny-burmakov commented 6 years ago

I have created new one dump without R# and Ghost doc (which also looks like a significant memory consumer). Consumption decreased to 960Mb, but it is still high in comparing with classic project style (300Mb).

https://developercommunity.visualstudio.com/content/problem/350936/memory-consumption.html

jmarolf commented 6 years ago

Internal report here

jmarolf commented 6 years ago

Looking at the latest memory dump 7 of the 10 top contributors are from the project system. Mostly having to do with the downstream effects of project nodes.

Name Count Size (Bytes) Inclusive Size (Bytes) Total
Microsoft.VisualStudio.Threading.AsyncEventHandler 1,435 54,700 70,620,412 78,494,500
Microsoft.VisualStudio.Project.OuterProjectNode 176 103,872 68,954,896 18,281,472
Microsoft.VisualStudio.Project.UnconfiguredProjectImpl 176 196,724 68,599,572 34,623,424
Microsoft.VisualStudio.Project.ProjectCapabilitiesScope 705 118,384 68,216,764 83,460,720
Microsoft.VisualStudio.Project.ProjectNode 176 159,928 55,621,064 28,147,328
Microsoft.VisualStudio.Project.ProjectConfigProvider 176 10,560 52,778,056 1,858,560
Microsoft.CodeAnalysis.CSharp.CSharpCompilation 254 1,054,668 37,982,172 267,885,672
Roslyn.Collections.Immutable.ImmutableHashMap+HashBucket<Microsoft.CodeAnalysis.ProjectId, Microsoft.CodeAnalysis.Project> 38 2,220 31,261,652 84,360
Microsoft.VisualStudio.Project.ConfiguredProjectImpl 176 87,920 30,968,576 15,473,920
Microsoft.VisualStudio.LanguageServices.RoslynVisualStudioWorkspace 1 148 28,733,552 148

@tmeschter are you familiar with any of these types in the course of investigating project nodes?

Pilchie commented 6 years ago

Most of these are CoreCPS. @lifengl has been looking at some of them I believe.

jmarolf commented 6 years ago

Talking to @tmeschter, this is all CoreCPS as @Pilchie stated. We can use this bug to track the work but unfortunately the pull requests that fix this are going to be internal.

evgeny-burmakov commented 6 years ago

I have observed that huge amount of time (about 5 minutes) on loading stage is taken by "Live code analysis" background task. Which also lead to memory peaks to 2.2 Gb and CPU loading up to 100%. As result till the end of the task VS almost unusable. Such behavior wasn't be observed on classic projects. Is it intended to have such task? And is any way to switch it off? I would rather expect that code analysis is performed in building time but not loading. "Full solution analysis" is switched off in my VS options.

Pilchie commented 6 years ago

"Live code analysis" encompasses a significant number of operations, some of which need to operate on the full solution even when the Full Solution Analysis is off. Tagging @sharwell and @heejaechang to take a look at the trace to see if there is anything unexpected there.

sharwell commented 6 years ago

I don't see anything that stands out as wrong. @evgeny-burmakov Do you happen to have (or can get) a trace and heap dump from an equivalent scenario to the last trace, but when using the old project system? This would allow a direct comparison of objects before/after the adoption of CPS.

evgeny-burmakov commented 6 years ago

@sharwell, sure, I can collect such trace. Is the trace which I reported correct? I did pause in tracing till the end of loading phase for collecting memory heap. But I not sure that event tracing is correct in such case. I can try to collect 2 new reports without pause.

sharwell commented 6 years ago

@evgeny-burmakov I was focused on the memory dump, which occurred at the end of the trace. I didn't notice any problems with the way it was collected.

heejaechang commented 6 years ago

@evgeny-burmakov so, only thing I see in the trace (for CPU) is we reading previous diagnostic data from persistent storage.

and see this from gcheap image

so there seems a lot of garbage created. we probably need to dig into see allocations at solution load.

heejaechang commented 6 years ago

I got the data above from this link https://developercommunity.visualstudio.com/content/problem/350936/memory-consumption.html

evgeny-burmakov commented 6 years ago

@sharwell, I have collected 2 new record with tracing of whole loading phase. It isn't fully equivalent solutions as development is in progress and now we already switched to SDK projects, but they almost similar.

Classic project, memory consumption about 400 Mb, loading time is fast: https://developercommunity.visualstudio.com/content/problem/354179/expected-memory-consumption-with-classic-projects.html SDK projects, memory consumption about 1GB, loading time noticeably higher: https://developercommunity.visualstudio.com/content/problem/354199/memory-consumption-with-sdk-projects.html

davkean commented 6 years ago

@evgeny-burmakov Thanks for the traces. I looked into them from the solution load perspective - unfortunately, the SDK trace goes for just over 11 minutes which is too long. Our recording has a circular buffer of approx. 30 seconds so most of the interesting events are thrown away - I see zero project system threads/allocations in that trace. The easiest way for us to proceed to avoid the back and forth is for us to privately grab the project structure (all the targets/projects involved - minus source files). Failing that, it might be first easier to proceed by first looking at telemetry event data to get an understanding of what portion of the load we need to capture.

For the later portion, the following would be helpful:

  1. Make note of exact time in UTC
  2. Open Visual Studio
  3. Open Classic solution
  4. Wait until it's loaded
  5. Close Visual Studio
  6. Make note of exact time in UTC
  7. Open SDK solution
  8. Wait until it's loaded
  9. Close Visual Studio

If you send me these times I can dig into the telemetry data which will give me information on what high-level events were occuring during those solution loads.

evgeny-burmakov commented 6 years ago

@davkean, There is loading time: Classic (7:51:51 UTC - 7:54:00 UTC) SDK (7:55:40 UTC - 8:01:30 UTC) Is it enough for analysis?

davkean commented 6 years ago

@evgeny-burmakov That was an ~hour ago? I'll find out tomorrow when the data comes in.

evgeny-burmakov commented 6 years ago

@davkean, yes, it was today (10/11/2018) about hour ago

sharwell commented 6 years ago

📝 Should it be necessary, the General Purpose strategy on the following page can be used to capture longer periods of time (likely the entire loading time for operations this short). I'm focused on a different aspect so I'm not using the traces right now, but I wanted to add the link in case @davkean or @heejaechang wants that data. https://github.com/dotnet/roslyn/wiki/Recording-performance-traces-with-PerfView

Pilchie commented 6 years ago

Assigning to @davkean to follow up on https://github.com/dotnet/project-system/issues/4078#issuecomment-428877365

lifengl commented 6 years ago

I am investigating a different report of the OOM from a different customer. The OOM happens inside language service initialization:

inside Microsoft.CodeAnalysis.ProjectDependencyGraph.ComputeReverseReferencesMap ... Microsoft.VisualStudio.ProjectSystem.LanguageServices.Handlers.MetadataReferenceItemHandler.AddToContextIfNotPresent ... Microsoft.VisualStudio.ProjectSystem.LanguageServices.LanguageServiceHandlerManager.HandleDesignTime

I wonder this is related to the language service doesn't handle CPS project in a batch, and causes bad memory problem (which is a known issue.) The namespace of the code is inside code analysis, so from external developer point of view, it is a part of code analysis. Roslyn team think code analysis as a more narrowed feature.

The dump file shows 1G memory allocated for System.Collections.Immutable.SortedInt32KeyNode`1[[System.Collections.Immutable.ImmutableHashSet`1+HashBucket[[Microsoft.CodeAnalysis.ProjectId, Microsoft.CodeAnalysis.Workspaces]], System.Collections.Immutable]] and a few Roslyn related types, which is the top 1st, 3rd types (2nd is string) in the managed heap. The odd thing is that those types are completely eliminated when I use PerfView to analysis the heap. PerfView actually points me to entire different set of types. The top type blamed by perfView actually uses 5% memory of this type, and easily lead the investigation to a wrong direction.

davkean commented 6 years ago

@jasonmalinowski ^ what release did your fix go into?

jasonmalinowski commented 6 years ago

The fix ended up going into Dev16, not 15.9, but we're handing bits to a customer (perhaps the same customer @lifengl is helping?) to look at a backport.

Pilchie commented 6 years ago

Yes, same customer.

evgeny-burmakov commented 6 years ago

Can I also have any dev version to evaluate if it match to our case?

jasonmalinowski commented 6 years ago

Looks like this is significantly improved by dotnet/roslyn#30758, so we're looking at merging that for 15.9.

Pilchie commented 5 years ago

@jasonmalinowski - this was in 15.9 Preview 5, right?

While we know that there is more work to do on memory use and scale for the new project system, I think this particular issue is addressed...

jasonmalinowski commented 5 years ago

Yes, it was. I'll close this as fixed, since at least this particular problem was indeed fixed.

evgeny-burmakov commented 5 years ago

I have validated 15.9 Preview 5. It isn't significant changes for our case. Memory consumption and loading phase almost the same as before. I have checked it few times.

jasonmalinowski commented 5 years ago

Hmm, @lifengl or @Pilchie do we want to re-look at traces from @evgeny-burmakov then with the fixes in place?

lifengl commented 5 years ago

A new set of dump files and traces will help us to analyze the problem.

evgeny-burmakov commented 5 years ago

Let me know which traces would be more suitable for analysis: ETW/telemetry/VS feedback report. As I remember feedback report skip part of trace information after defined time range. If ETW is prefered, plz point how to collect correct data (which providers should be enabled).

evgeny-burmakov commented 5 years ago

Any news? Do you need new traces?

drewnoakes commented 5 years ago

@evgeny-burmakov if you're on 15.9 with Jason's fixes, then a new dump would be useful. Ideally without ReSharper or GhostDoc loaded.

Open a new VS instance without any solution loaded. Then use the feedback system to "Report a problem". Start recording, load the solution, and when the solution's loaded, stop recording. I believe that should suffice. Even if the solution load takes longer than 30 seconds, we should still be able to see something useful in the dump.

To know when to stop recording, you might use have the test explorer open and stop recording when unit tests are displayed.

evgeny-burmakov commented 5 years ago

@drewnoakes, there is new dump from VS 15.9.2: https://developercommunity.visualstudio.com/content/problem/388637/new-dump-for-vs-1592-related-to-issue.html

lifengl commented 5 years ago

Yeah, I can find the dump attached to the new feedback item. 1/3 of heap is freed objects. After excluding those, Roslyn uses about 29% of the heap. Maybe @sharwell can help to take a look whether it is expected? The dump also shows a few issues we fixed in dev 16 preview 1, including a memory leak in the design time build service (9% heap), excessive memory usage in dataflow (15%). Preview 1 has been shipped, so @evgeny-burmakov , can you try Dev 16 preview 1 to see whether your scenario is improved in the new preview release? There are still some working to reduce memory usage related to the dependencies tree.

evgeny-burmakov commented 5 years ago

@lifengl, I have verified VS 16 Preview 1. It is significant better in correspond to loading phase time than VS15.9.x. Memory consumption changes from loading to loading and it is from 500Mb (what is close to expectation) to 1Gb.

cartermp commented 5 years ago

@evgeny-burmakov Have you had a chance to see if that observation held for VS 2019 GA?

jaytonic commented 4 years ago

We have the same issue. As of today, we had to stop our migration to .Net Core, because VS was crashing(non-stop Out of memory exception).

What is the status on this? For us it's a big issue: end of the year we have to start a new app in our solution which will be an ASP.Net Core app, so we need to be able to switch to this project style. To say how it impacts us, we are even considering jetbrain's editor.

Having VS2019 in 64 bit would at least give us a workaround.

(We have a bit less than 400 projects, we already near 2Gb of memory usage without the new project style)

drewnoakes commented 4 years ago

@jgrossrieder we are investing heavily in performance improvements. In VS16.7 (you can try previews now) we have reduced memory consumption by SDK-style projects considerably.

Are you able to share more details about your solution? Please try opening in a 16.7 preview and, if it doesn't crash right away, use the "Report a problem" feature to open a ticket and include all the diagnostics it produces. If it OOMs before you're able to use that feature, can you get a 32-bit dump of the process manually and attach it to a ticket on Developer Community. Either way, link the ticket here and I'll take a look.

Analyzing a range of solutions allows us to find opportunities to further reduce memory consumption in VS.

DocteurRe commented 4 years ago

@drewnoakes Hi, I'm working in the same team as @jgrossrieder. We tried to use VS16.7 preview 3. We saw some significative improvments, but this is still not usable for us.

I reproduced our issue using the "Report a problem" feature and then created the following ticket: https://developercommunity.visualstudio.com/content/problem/1091989/enormous-memory-and-cpu-consumption-resulting-a-cr.html

Thanks a lot for taking a look at it.

cartermp commented 4 years ago

Not sure how helpful a trace would be here since it takes 7-8 minutes to crash, but one possibility is to use a second VS instance to collect an ETL trace for a sample of that time(1-2 minutes perhaps). This gives detailed information about what is contributing to memory and CPU usage for that sample time - though it is ultimately just a sample, so picking the right time to sample is a bit of a technique itself.

There's a guide for that documented here: https://github.com/dotnet/roslyn/wiki/Reporting-Visual-Studio-crashes-and-performance-issues#performance-issues

Though I'd defer to @drewnoakes and @panopticoncentral on if this would be useful for any performance analysis at this stage.