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

Perf issues opening thousands of documents #35996

Closed
saurabhiam opened this issue Oct 10, 2017 · 41 comments
Closed

Perf issues opening thousands of documents #35996

saurabhiam opened this issue Oct 10, 2017 · 41 comments
Labels
bug Issue identified by VS Code Team member as probable bug freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues perf
Milestone

Comments

@saurabhiam
Copy link

  • VSCode Version: Code 1.17.0 (be377c0, 2017-10-04T23:33:45.303Z)
  • OS Version: Linux x64 4.10.0-37-generic
  • Extensions: the listing length exceeds browsers' URL characters limit

VSCode consuming high amount of CPU & memory on startup and becomes unresponsive.
I get "Window is not responding" message

Here's the CPU usage snapshot
screenshot from 2017-10-10 23-23-21

Steps to Reproduce:

  1. Open VSCode
  2. Critical unresponsiveness is observed when vscode opens with an existing project with some files open.

Reproduces without extensions: No

@egamma egamma added the info-needed Issue requires more information from poster label Oct 11, 2017
@egamma
Copy link
Member

egamma commented Oct 11, 2017

@Saurabh-Sharma what kind of project (language, size) is this?

Since you mention that this cannot be reproduced without extensions, can you please help us to narrow down which extension is causing this: uninstall an extension, restart, observe whether problem persists. I understand that this painful since you have many extension installed. I would start with the extension that provides language services.

@saurabhiam
Copy link
Author

@egamma I am using React over my project.
The issue was being caused by IntelliSense for CSS class names

On removing the extension, vscode worked fine.

Although the same is working fine with the version prior to VSCode Version: Code 1.17.0 (be377c0, 2017-10-04T23:33:45.303Z)

@egamma
Copy link
Member

egamma commented Oct 12, 2017

@Saurabh-Sharma thanks for following up. The fact that you say the extension wasn't a performance issue before 1.17 is a valuable hint that would help us to track the root cause of this issue.

update we believe that this is caused that in 1.17 the node_modules folder is no longer excluded when an extension is using the API vscode.workspace.findFiles (see next comment). To confirm this:

  • is this an project that you can share and that we can profile? If not can you create a CPU profile for us (steps below).
  • in your settings do you configure files.exclude or search.exclude?
  • in your .gitignore file do you exclude node_modules?

If the workspace is not sharable can you do a CPU profile when the extension is installed. These are the Hit F1 > Toggle Developer Tools. In the overflow menu (see below) select 'More Tools > JavaScript Profiler'. In there select start, let it profile for 30 to 60 seconds, stop it, save it to a file and attach the file here. Since the problem happens on start-up reload the window after you started the profiler using F1>Reload Window.

screen shot 2017-09-28 at 09 44 31

@egamma egamma self-assigned this Oct 12, 2017
@egamma egamma added this to the September Recovery 2017 milestone Oct 12, 2017
@egamma
Copy link
Member

egamma commented Oct 12, 2017

The extension that triggers the CPU load is using:

vscode.workspace.findFiles(`**/*.{${languages}}`, '')` 

in 1.17 we have switched to use ripgrep. This has changed the defaults that are excluded from workspace.findFiles. When node_modules is not excluded in .gitignore then the node_modules folder is no longer excluded by default. I've confirmed this by using the extension with 1.16.

The proposed fix is:

  • change findFile back to the old behaviour and to exclude node_modules by default. While this is not specified in the API, we should do this to avoid performance problems caused by extensions that rely on the old behaviour. There are several other extensions using this API function and they are affected by this (Docker, csharp, vscode-icons, ruby, typescript hero, ...)
  • Make a PR against the CSS Intellisense extension.

@egamma egamma added the candidate Issue identified as probable candidate for fixing in the next release label Oct 12, 2017
@egamma egamma assigned chrmarti and roblourens and unassigned egamma Oct 12, 2017
@egamma
Copy link
Member

egamma commented Oct 12, 2017

The PR for the extension has been submitted zignd/HTML-CSS-Class-Completion#89

@egamma
Copy link
Member

egamma commented Oct 12, 2017

To reproduce the issue in VS Code.

  • Install the HTML Hint, Markdown Lint extensions (they will report issues inside node modules)
  • In VS Code 1.16, install the CSS Intellisense extension
  • Git clone a repository with node modules with some markdown/html files. I've used https://github.com/Microsoft/vscode-npm-scripts.
  • Open this workspace in VS Code
    Observe that the Problems View is empty.

Now do the same steps in VS Code 1.17. The Problems View will contain many errors, which shows that workspace.findFiles also returns files inside the node_modules folder. These files are then opened by the extension which triggers the linters, which then report errors against the files in node_modules.

@chrmarti
Copy link
Contributor

I see the problem reported in 1.16.1 too:
image

@roblourens
Copy link
Member

roblourens commented Oct 12, 2017

I think in #34434 and #34487 we discovered that node_modules and .git/ was never excluded, so I don't think that aspect of it is new. I still believe that we should apply files.exclude or just exclude those two by default.

Edit - I guess that was just for workspaceContains, never mind

@chrmarti
Copy link
Contributor

findFiles() does apply files.exclude but not search.exclude which lists node_modules by default. My screenshot above the code indicate that node_modules wasn't excluded in 1.16.x.

@Saurabh-Sharma The CSS Intellisense extension just published a new version with the suggested fix. Could you check if you still see the problem with that newer version?

@egamma
Copy link
Member

egamma commented Oct 12, 2017

@chrmarti hmm, below is a screen shot from my setup and it shows that node_modules was excluded. My screenshot is from 1.16 and yours is from 1.16.1. So this means that 1.15 did exclude node_modules.

image

@chrmarti
Copy link
Contributor

@egamma Did the extension auto-update in your install? Your change is already published in a new version. Do you have files.exclude set to something else than the default?

@jrieken When I open one of my large workspaces the 'Intellisense for CSS class names' extension quickly gets both 1.16 and 1.17 locked up. Spending a lot of time comparing URIs in: https://github.com/Microsoft/vscode/blob/master/src/vs/workbench/api/electron-browser/mainThreadDocumentsAndEditors.ts#L107

Still looking for the regression.

@jrieken
Copy link
Member

jrieken commented Oct 12, 2017

I'd say that's the effect of opening many, many documents. On every change we need to sync the documents and editor over. @chrmarti Do you have a real CPU profile that you can share?

@chrmarti
Copy link
Contributor

@jrieken I do and I think you're right. I wonder if computing the diff with a set/map instead of sorted arrays would be faster. I've copied the profiles I currently have to //mt1/eng/35996, the one I'm currently looking at is the -master which is from unminified source.

@sandy081 Another hot spot in the profile is ConfigurationModel.override() that gets triggered from FileService.configuredAutoGuessEncoding(). That I haven't seen in the 1.16.1 profile, but I need to double-check.

I don't think we can explain the reported regression yet. 1.16 performs just as badly with that many opened documents as 1.17.

@chrmarti
Copy link
Contributor

image

@diminutivesloop
Copy link
Contributor

I'm seeing a similar issue, but it manifests even when I have no open projects and all extensions are disabled.
vscode startup cpu usage

@chrmarti
Copy link
Contributor

@diminutivesloop That looks like a different problem, could you open an new issue (Help > Report Issues)? Thanks.

@chrmarti
Copy link
Contributor

@sandy081 ConfigurationModel.override() could clone the contents only when the first override that needs to be merged is found. For FileService.configuredAutoGuessEncoding() this could be optimized further because that only needs a single value, no need to compute the full config first.

The document sorting is the bigger issue though.

jrieken added a commit that referenced this issue Oct 30, 2017
@jrieken jrieken removed their assignment Oct 30, 2017
@bpasero
Copy link
Member

bpasero commented Oct 30, 2017

@jrieken tried with your steps and those textFileEditorModel methods are not showing up in the top consuming methods for me, can you reproduce reliably and if so is there more to it than running #35996 (comment) on the vscode workspace?

My trace:
CPU-20171030T121210.cpuprofile.txt

Looking at your trace, the top consuming method seems to be this onStateChange handler which should be a no-op unless files are being reverted.

@bpasero bpasero added the info-needed Issue requires more information from poster label Oct 30, 2017
@jrieken
Copy link
Member

jrieken commented Oct 30, 2017

Yes, always reproduces. @bpasero Did you really run this on our workspace with thousands of documents (4414 to be precise)? Your longest single method runs for just a 1sec, I have runtime in the area of 10-30seconds.

@bpasero
Copy link
Member

bpasero commented Oct 30, 2017

@jrieken tried on vscode workspace and I am seeing ~1700 files returned but I can try with more files.

@bpasero
Copy link
Member

bpasero commented Oct 30, 2017

@jrieken seems better to me after 40b58af can you check?

@jrieken
Copy link
Member

jrieken commented Oct 30, 2017

Yeah, seems a lot better now, mostly garbage collecting (we should memory profile this) and object-clone (/cc @sandy081 on that)

after.cpuprofile.txt
screen shot 2017-10-30 at 16 51 29

@bpasero
Copy link
Member

bpasero commented Oct 30, 2017

I also noticed the cloning appearing to the top.

@bpasero bpasero assigned sandy081 and unassigned bpasero Oct 30, 2017
@bpasero bpasero removed this from the October 2017 milestone Oct 30, 2017
@sandy081
Copy link
Member

sandy081 commented Oct 30, 2017

@bpasero @jrieken

Configuration is always cloned when is being asked, otherwise there could be a chance of changing the value in-memory which is error-prone. May I know where are the majority of the calls reading configuration are coming from ?

I see, in most of the places, we are asking the complete configuration even though we need value for a section or for a key. Making it specific, might reduce the cloning time.

@bpasero
Copy link
Member

bpasero commented Oct 30, 2017

Looks like some calls are originating from file service finding out the configured encoding for each resource that gets loaded (here).

@jrieken
Copy link
Member

jrieken commented Oct 31, 2017

Configuration is always cloned when is being asked, otherwise there could be a chance of changing the value in-memory which is error-prone.

@sandy081 Why not call object.freeze/deepfreeze once when creating those objects?

@sandy081
Copy link
Member

@jrieken I have to do deepFreeze, but did not find a native deepFreeze method. If we do deepFreeze ourselves, won't be similar to deepClone?

@jrieken
Copy link
Member

jrieken commented Oct 31, 2017

We used to have deepFreeze in objects.ts but we might have removed (unused). The idea is to walk the object recursively and freeze it in place (Object.freeze modifies the argument)

If we do deepFreeze ourselves, won't be similar to deepClone?

Well, you only do it once, when you compute/write the data, but not everytime you are asked for configuration (reading).

@vscodebot
Copy link

vscodebot bot commented Nov 7, 2017

This issue has been closed automatically because it needs more information and has not had recent activity. Please refer to our guidelines for filing issues. Thank you for your contributions.

@bpasero bpasero reopened this Nov 7, 2017
@bpasero bpasero removed the info-needed Issue requires more information from poster label Nov 7, 2017
@sandy081
Copy link
Member

sandy081 commented Dec 4, 2017

Configuration service was made faster by not cloning always instead of freezing once and surfacing frozen object.

@sandy081 sandy081 closed this as completed Dec 4, 2017
@sandy081 sandy081 removed their assignment Dec 4, 2017
@vscodebot vscodebot bot locked and limited conversation to collaborators Jan 18, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Issue identified by VS Code Team member as probable bug freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues perf
Projects
None yet
Development

No branches or pull requests

10 participants