3
Vote

Visual Studio memory grows from 300M to 2G in one hour

description

While simply editing Python code in the editor, over the course of an hour Visual Studio 2013 gradually becomes more sluggish and eventually becomes unusable consuming 2G of memory. I captured a dump and analyzed it in Visual Studio 2013 dump analyzer and a screenshot of the manage memory view is attached.

Hand copying a couple of the leading Managed Memory (devenv.exe) offenders:

Microsoft.VisualStudio.Text.Implementation.TextVersion, count 10k, size 500k inclusive bytes 874M
Microsoft.PythonTools.AnalysisAnalyzer.TypedDependencyInfo, count 900k, size 42M, inclusive bytes 640M

I still have the 2.4G devenv.dmp file (and can easily repro the leak) but cannot upload it to you as it contains proprietary code. However, I can run any analysis you suggest and send you the sanitized results.

I do have several extensions loaded, nothing too fancy. I disabled most extensions to no avail but I cannot realistically disable VsVim and get any work done.

file attachments

comments

Zooba wrote Jan 24 at 9:48 PM

Excellent, I've been keen for someone to hit this and be able to help us out :)

The first thing I'll ask for is the Diagnostic Info (Tools->Python Tools->Diagnostic Info), just to save asking 10 different questions about versions/interpreters/extensions/etc. It may have some local paths in it that you can find/replace, and it will likely include a list of whatever Python modules you have installed - I don't think we'll need to worry about those so censor them if it's important, but I'd rather not have entire lines deleted. You can drop the whole thing in a text file and email to ptvshelp@microsoft.com - this is only seen by our team (same for any other details you don't want to put up in public, though we prefer to keep whatever we can on here for tracing and future reference).

TypedDependencyInfo is one of the classes we'd expect to see a lot of when your code has some obscure case that we aren't analyzing correctly. We do have some ways to figure out what's causing this, though they're mostly not easy unless you're actually debugging PTVS. I'll take some time and figure out a way you can do it and track down the culprit.

However, TextVersion is a bit of a surprise, since it's a core part of VS. I don't know what "normal" looks like for that, but it's possible we're keeping them alive somehow when they should have been freed. I'll take a look at how many of those we'd normally have.

jrs wrote Jan 26 at 7:20 PM

I let memory grow to 2G, took a diagnostics dump, and then emailed it to the address you specified.

Zooba wrote Jan 27 at 4:12 PM

Thanks. I suspect that the problem is due to a combination of having multiple projects with search paths that include all the other projects.

I'm reviewing our code that handles this now to see how it may be causing your issue, but you can also help test it by temporarily removing the search paths from your project. This will probably lose completions for modules imported from other projects, but we do have some handling for cross-project imports so perhaps not (though the importable names may be different).

If you add a sys.path.append(...) call early in your startup project then you will still be able to run and debug fine. (Search paths from non-startup projects are ignored when running a project.) I'd imagine you'll see pretty quickly whether we are leaking memory - in general, we should stabilize after loading your projects and will only grow significantly if a lot of code is added.

Zooba wrote Jan 27 at 5:32 PM

One other thing to check is whether you can reduce memory usage by unloading projects or closing the solution. Typically, the leaks that we suffer from keep our objects alive even after the solution is closed.

I've already found one leak that may be what you are suffering from - we may be keeping the editor control alive even after closing the window, which indirectly keeps all of the TextVersion objects alive. I've fixed that one and am now chasing down a few more, but it'll be handy to know if this is going to find the same issue that you're seeing.

jrs wrote Jan 28 at 5:20 AM

I will try the removing the search paths next but tonight I tried the "closing the solution" test.

I let virtual memory grow to 2G, closed the solution (which froze Visual Studio for many seconds) but saw no change in the memory footprint as far as task manager was concerned. Wondering if it just needed a good GC, I opened a different non-Python solution and memory continued to grow. I closed that and I reopened the problematic solution and continued editing and memory grew to 2.3G, which surely must have provoked an aggressive GC, but lags continued with no reduction in memory footprint. So the roots of the leaked references do not appear to be exclusively contained in project, solution and editor data structures.

Zooba wrote Jan 28 at 5:25 PM

It certainly sounds like you're hitting the leak that I've recently fixed, though it's interesting that you are seeing it much worse than anyone else (or at least, nobody else has bothered to report it). Are you working on a lot of files? Or are they particularly large?

On a positive note, we should have a dev build ready by the end of the week with the fix (among other improvements/regressions). I'll let you know when we put it up, since we normally send them out without fanfare, so it'd be great if you can test with that. Hopefully there are no major blockers in it that will cause you to have to go back to 2.0, but if there are then we'd like to hear about those too :)

(Side note: Process Explorer has a .NET Performance panel for running processes that will show you how many GC collections have occurred. I don't doubt that at least one happened between 2GB and 2.3GB, but this is an easy way to check.)

Zooba wrote Jan 29 at 3:58 PM

I just published a dev build with the fix for this. Can you try it out and see if the situation has improved?

If not, I'll be looking for more information about the actions you take while editing (e.g., how often you open/close editors, how much text you add/remove/change, how often you switch tabs, etc.) - the sort of thing that would be obvious if I were watching over your shoulder, but are hard to see from this side of the internet :)

jrs wrote Jan 29 at 4:05 PM

I tried the experiment of removing the relative search paths from all the projects, but there was no change in the memory growth. Next I'll try the dev build. Thanks for your help so far.

jrs wrote Jan 30 at 4:10 AM

I installed the latest dev version but I am sorry to say the leak is still there.

I found a more structured repro:
  • Open the problematic solution
  • Delete lines from a 600-line file repeatedly until the buffer is empy
  • Undo repeated until the file is restored
  • Repeat ten times
This causes memory to grow from 400M to 1.8G. I captured a DMP file (analysis attached).

Next I will try to repro with an open source project.

jrs wrote Jan 30 at 4:47 AM

OK, I have a repro that does not involve my code base. I choose the NLTK project, since I am familiar with that. I forked the project's repo on GitHub and added a Visual Studio project and solution, pretty much just by using the wizard to import from existing code. My fork of the repository is here:
Then, in that solution, I just opened nltk/parse/chart.py, and did the "delete lines from the top" procedure, followed by repeated undo. This is a longish file and it only took two passes to bring memory up to 2G. Then I took a DMP snapshot which has a different set of "most prevalent objects" than my DMPs do but there are still an inordinate number of the ones that show in my dump (but further down in the NLTK one).

jrs wrote Jan 30 at 6:50 AM

I repeated the NLTK experiment with all discretionary extensions disabled. I think all the remaining extensions are either installed by default with VS2013 or are part of PTVS. In any case, the are all MS-official extensions.

I got the same results: two passes through nltk/parse/chart.py => 1.8G. Hold down Ctrl+X to delete lines and then hold down Ctrl+Z to restore them. With all this, I hope you can repro the leak yourself and then the debugger answers all questions.

Attached is my diagnostics info while in this state performing this test.

Zooba wrote Jan 30 at 9:17 PM

Thanks for that. I can repro the issue with the entire project open, though not with the file on its own. I now believe the leak is due to us not cleaning up our code analysis properly as the project is edited. Now I have a repro I can try and track it down, though it's already looking complicated enough that we may not have a fix for 2.1 alpha. (It will certainly be fixed for 2.1 beta, but the scenarios we want feedback on from the alpha won't be significantly affected by this.)

Thanks for helping us track this down.

Zooba wrote Feb 12 at 11:52 PM

I've fixed a whole range of reference leaks (and potential leaks), though they won't be in PTVS 2.1 Alpha.

Keep an eye out for out next dev build (there are email notifications available), which will have the fixes.

jrs wrote Feb 13 at 12:09 AM

Thanks, I will report back after I've tested the next dev build.

Zooba wrote Feb 25 at 11:16 PM

There's a new dev build out that has the fixes. It should be much closer to being leak-free, though I'm still not prepared to guarantee it :) . You can get it from here (bearing in mind the usual warnings - this is more alpha than our alphas usually are).

jrs wrote Feb 28 at 9:57 PM

Thanks for your work on this problem.

I tried the February 21st dev build, and while the leak problem seems greatly improved, it is still quite clearly there and is easily reproducible using the NLTK project experiment I outlined above. After three passes through the file memory exceeds 2G and does not compact. Same basic profile when analyzing the DMP file.

From a more practical view, for my daily use interaction with the project I still have to restart Visual Studio several times a day to prevent memory growth and increasing sluggishness and delays editing. Worse is that Visual Studio is now often, for no apparent reason, continually analyzing the project using up one full core continuously for long periods of time, even when I am not editing the solution. Then, just as suddenly, the CPU use will go to zero.

The big CPU use is a serious problem as the laptop gets hot and doesn't last on the battery and I'm going to try going back to 2.0 to resolve that issue.

I don't really have the wherewithal the see what is using the problem but I tried attaching with the debugger and got this stack trace:
System.Core.dll!System.Collections.Generic.HashSet<Microsoft.PythonTools.Analysis.AnalysisUnit>.AddIfNotPresent(Microsoft.PythonTools.Analysis.AnalysisUnit value) Unknown
System.Core.dll!System.Collections.Generic.HashSet<System.__Canon>.Add(System.__Canon item) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.DependencyInfo.AddValue(ref System.Collections.Generic.ISet<Microsoft.PythonTools.Analysis.AnalysisUnit> references, Microsoft.PythonTools.Analysis.AnalysisUnit value)  Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.DependentData<System.__Canon>.AddDependency(Microsoft.PythonTools.Analysis.AnalysisUnit unit) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Values.IterableInfo.GetEnumeratorTypes(Microsoft.PythonTools.Parsing.Ast.Node node, Microsoft.PythonTools.Analysis.AnalysisUnit unit) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Values.ListInfo.ListExtend(Microsoft.PythonTools.Parsing.Ast.Node node, Microsoft.PythonTools.Analysis.AnalysisUnit unit, Microsoft.PythonTools.Analysis.IAnalysisSet[] args, Microsoft.PythonTools.Parsing.Ast.NameExpression[] keywordArgNames) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Values.SpecializedCallable.Call(Microsoft.PythonTools.Parsing.Ast.Node node, Microsoft.PythonTools.Analysis.AnalysisUnit unit, Microsoft.PythonTools.Analysis.IAnalysisSet[] args, Microsoft.PythonTools.Parsing.Ast.NameExpression[] keywordArgNames)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.ExpressionEvaluator.EvaluateCall(Microsoft.PythonTools.Analysis.Analyzer.ExpressionEvaluator ee, Microsoft.PythonTools.Parsing.Ast.Node node)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.ExpressionEvaluator.EvaluateWorker(Microsoft.PythonTools.Parsing.Ast.Node node)  Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.DDG.Walk(Microsoft.PythonTools.Parsing.Ast.ExpressionStatement node) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.ExpressionStatement.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.DDG.Walk(Microsoft.PythonTools.Parsing.Ast.SuiteStatement node)  Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.SuiteStatement.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.IfStatementTest.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.IfStatement.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.DDG.Walk(Microsoft.PythonTools.Parsing.Ast.SuiteStatement node)  Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.SuiteStatement.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.IfStatementTest.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.IfStatement.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker)    Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.DDG.Walk(Microsoft.PythonTools.Parsing.Ast.SuiteStatement node)  Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Parsing.Ast.SuiteStatement.Walk(Microsoft.PythonTools.Parsing.Ast.PythonWalker walker) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.FunctionAnalysisUnit.AnalyzeWorker(Microsoft.PythonTools.Analysis.Analyzer.DDG ddg, System.Threading.CancellationToken cancel)   Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.Analyzer.DDG.Analyze(Microsoft.PythonTools.Analysis.Deque<Microsoft.PythonTools.Analysis.AnalysisUnit> queue, System.Threading.CancellationToken cancel, System.Action<int> reportQueueSize, int reportQueueInterval) Unknown
Microsoft.PythonTools.Analysis.dll!Microsoft.PythonTools.Analysis.PythonAnalyzer.AnalyzeQueuedEntries(System.Threading.CancellationToken cancel)    Unknown
Microsoft.PythonTools.dll!Microsoft.PythonTools.Intellisense.AnalysisQueue.GroupAnalysis.Analyze(System.Threading.CancellationToken cancel) Unknown
Microsoft.PythonTools.dll!Microsoft.PythonTools.Intellisense.AnalysisQueue.Worker(object threadStarted) Unknown
mscorlib.dll!System.Threading.ThreadHelper.ThreadStart_Context(object state)    Unknown
mscorlib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool preserveSyncCtx)   Unknown
mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool preserveSyncCtx)   Unknown
mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Unknown
mscorlib.dll!System.Threading.ThreadHelper.ThreadStart(object obj)  Unknown

Zooba wrote Feb 28 at 11:22 PM

Ergh, how frustrating.

If you do try an earlier version, let me know if it makes any difference. I'll be surprised if it does (unless you go back to 1.5 or earlier), since we haven't changed this part of the code much recently.

Unfortunately, stack traces aren't very helpful once they go through DDG.Analyze - I really need before/after memory dumps, preferably involving as few steps as possible. I have a tool to help automate this now, so when I find some time I can dig deeper. Right now we're a little pressed with some releases coming up, but hopefully I'll get a chance before we ship 2.1 final.

jrs wrote Mar 3 at 4:10 PM

Today with the February 21st dev build, the computer was running hot again. Stack trace showed Intellisense analyzer running. It was literally running for 30 minutes with no editing at all. What could it possibly be analyzing for so long when Python can compile the whole project to byte code is a few seconds? It never finished and I had to close Visual Studio.

Anyway, I just reverted to PTVS 2.0 VS 2013, opened the same solution, and it used one full core for only about one minute and then stopped, as desired. The leak is much worse in the 2.0 build but I will first confirm that the CPU usage problem is not present before moving forward to 2.1 Alpha and retesting.

jrs wrote Mar 3 at 4:13 PM

I should add that, ironically, memory is completely stable during the high CPU usage scenario. Memory didn't budge at all for 30 minutes.

Zooba wrote Mar 3 at 5:33 PM

Are you referring to the separate process using 100% CPU or Visual Studio?

The one that runs as a background process is a one-time action, necessary to seed the completion DB. After it has finished, we only make progressive updates to it when you install new packages (unless you directly modify the standard library itself, in which case we run the whole thing again).

This takes a lot longer than bytecode compilation because we are actually executing all of the code (in a simulation) with every possible type that gets passed to it. This is how we can provide information about return types from functions, since Python itself does not know or care about that information. It will also run over all the packages you have installed, so if you've started with a distribution like pythonxy or Canopy, it may be running for over an hour.

While it is running, you can open the Environments List in PTVS and it will show you the progress. If it is not making any progress, we would be interested to know where it is stuck (the progress bar has a tooltip that will tell you), since occasionally we will hit a code construct that doesn't analyze well. If we can narrow this down to a specific version of a particular package, we should be able to reproduce and fix it.

That said, this should be completely separate from the memory leak in VS. It is expected behavior (that isn't well explained unless you really go and read through all the documentation, sorry) and we aren't able to fix it any time soon without severely crippling IntelliSense.

If, however, the devenv.exe process is running hot for a long time after opening a project, that is something we would like to fix. Especially if it wasn't happening in earlier versions.

jrs wrote Mar 3 at 6:19 PM

No, I am aware that the separate process analyzes my various Python environments. The 30 minute CPU usage was coming directly from DevEnv.exe itself, and its stack trace when I looked at it started with PythonTools.Intellisense.AnalysisQueue.Worker like the stack trace reported above.

Because of the "Find in Files" crash I am now forced to use Visual Studio 2012 now but I am currently at PTVS 2.0 released version without any apparent CPU usage problems. I'll keep an eye on it.

Zooba wrote Mar 3 at 8:38 PM

Sorry you've had to roll back to earlier versions. When I get a chance I'll review what's changed since 2.0 that may be leading to our analysis not completing.

jmwachtel wrote Mar 31 at 1:29 PM

I have this problem in Visual Studio 2013 for versions 2.0, 2.1 alpha, and the latest development build.

slishak wrote Apr 14 at 2:51 PM

Just thought I'd pitch in too - I've also been encountering this problem (reproducible by editing a large .py file, >2500 lines). I've just installed PTVS 2.1 Beta on VS2012 and the issue is still there, doesn't seem any better or worse than 2.1 Alpha.