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

Extension Host Process can be completely overwhelmed by file system event during background builds, and make extensions stop to response user actions #194341

Closed
lifengl opened this issue Sep 27, 2023 · 19 comments
Assignees
Labels
extension-host Extension host issues file-watcher File watcher freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues info-needed Issue requires more information from poster
Milestone

Comments

@lifengl
Copy link
Member

lifengl commented Sep 27, 2023

VS code extension host can be completely overwhelmed by file watcher events, and during that period of time, extensions will stop responding to user actions.

Does this issue occur when all extensions are disabled?: No

  • VS Code Version: 1.82.2
    Version: 1.82.2 (user setup)
    Commit: abd2f3d
    Date: 2023-09-14T05:55:25.390Z
    Electron: 25.8.1
    ElectronBuildId: 23779380
    Chromium: 114.0.5735.289
    Node.js: 18.15.0
    V8: 11.4.183.29-electron.0

  • OS Version:
    OS: Windows_NT x64 10.0.22621

Steps to Reproduce:

  1. Get latest OrchardCore, open workspace on the root of the repo
  2. try to use latest C# Dev Kit extension, expand the solution explorer tree
  3. start to clean build the solution, either through the extension or on the command line with a different windows terminal
  4. wait build really starts to compile projects (after the initial NuGet restores)
  5. try to expand the solution explorer item, it spins forever (will resume only after a long time even build ends)
  6. other extension will stop responding in a similar way

Take a CPU profile with vs code built-in development tool, the extension host is completely blocked by file system events.

image

@lifengl
Copy link
Member Author

lifengl commented Sep 27, 2023

loop in @isidorn

@chrmarti chrmarti assigned bpasero and unassigned chrmarti Sep 28, 2023
@bpasero bpasero added freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues file-watcher File watcher labels Sep 28, 2023
@bpasero
Copy link
Member

bpasero commented Sep 28, 2023

@lifengl for this case it would probably make sense to exclude more directories from watching via the files.watcherExclude setting. Can you find the origins of the large amount of file events and try to configure the setting accordingly? We can think about pushing more patterns to our default exclude list so that it applies to all our users:

'files.watcherExclude': {
'type': 'object',
'patternProperties': {
'.*': { 'type': 'boolean' }
},
'default': { '**/.git/objects/**': true, '**/.git/subtree-cache/**': true, '**/node_modules/*/**': true, '**/.hg/store/**': true },
'markdownDescription': nls.localize('watcherExclude', "Configure paths or [glob patterns](https://aka.ms/vscode-glob-patterns) to exclude from file watching. Paths can either be relative to the watched folder or absolute. Glob patterns are matched relative from the watched folder. When you experience the file watcher process consuming a lot of CPU, make sure to exclude large folders that are of less interest (such as build output folders)."),
'scope': ConfigurationScope.RESOURCE
},

@bpasero bpasero added the info-needed Issue requires more information from poster label Sep 28, 2023
@bpasero
Copy link
Member

bpasero commented Sep 28, 2023

fyi @jrieken on the perf trace that seems to spend a substantial time in uri.fsPath. We call it here for each and every file event:

const subscription = dispatcher(events => {
if (!ignoreCreateEvents) {
for (const created of events.created) {
const uri = URI.revive(created);
if (parsedPattern(uri.fsPath) && (!excludeOutOfWorkspaceEvents || workspace.getWorkspaceFolder(uri))) {
this._onDidCreate.fire(uri);
}
}
}
if (!ignoreChangeEvents) {
for (const changed of events.changed) {
const uri = URI.revive(changed);
if (parsedPattern(uri.fsPath) && (!excludeOutOfWorkspaceEvents || workspace.getWorkspaceFolder(uri))) {
this._onDidChange.fire(uri);
}
}
}
if (!ignoreDeleteEvents) {
for (const deleted of events.deleted) {
const uri = URI.revive(deleted);
if (parsedPattern(uri.fsPath) && (!excludeOutOfWorkspaceEvents || workspace.getWorkspaceFolder(uri))) {
this._onDidDelete.fire(uri);
}
}
}
});

To figure out if the extension provided pattern matches the event path. If you have ideas how to make this more efficient, please let me know. Maybe there could be a "fast" variant of .fsPath that still works with our glob library but is less correct since we do not use this path actually in node.js

@jrieken
Copy link
Member

jrieken commented Sep 28, 2023

Maybe there could be a "fast" variant of .fsPath that still works with our glob library but is less correct since we do not use this path actually in node.js

Why do we use fsPath to begin with? Isn't path the better and more correct approach anyways? Do glob patterns support UNC roots and backward slashes?

@jrieken
Copy link
Member

jrieken commented Sep 28, 2023

@lifengl Can you please share the profile that you captured? I don't see this with a similar setup (npm install and watching node_modules) but it might be OS specific. On macOS I see nice, smallish chunks for events that get processed without much blocking

@bpasero
Copy link
Member

bpasero commented Sep 28, 2023

@jrieken yeah I think .path is fine on Linux and macOS. On Windows here is the difference I observe:

  • c:\foo\bar becomes /c:/foo/bar
  • \\localhost\c$\foo\bar becomes /c$/foo/bar

Our glob lib can deal with backslash vs slash fine, i.e. ignores the difference. But I think the leading / and the fact that the UNC authority is not there can be an issue for some existing patterns.

@jrieken jrieken self-assigned this Sep 28, 2023
@lifengl
Copy link
Member Author

lifengl commented Oct 2, 2023

I sent CPU profiles captured earlier to you. it seems to be that Roslyn team chained events, so they may have better ideas on the patterns they have. During build, lots of output items are .dll/.pdb and other files. The number might be exploded due to projects referencing others are coping referenced output into its own output folder.

I wonder certain limited globbing patterns can be matched more efficiently without converting a file path, especially ones matching file extensions or an exact file name like /*.cs can be efficiently checked with Uri. patterns like [BasePath]//*.[Extension] might be quite common in real usages.

@lifengl
Copy link
Member Author

lifengl commented Oct 2, 2023

also, another consideration is that fsPath will be called once per-watcher registration, and each time it would create a new string, so when an extension adds many watchers (maybe for different folders), it can grow to be a scalability problem.

@bpasero
Copy link
Member

bpasero commented Oct 3, 2023

One relatively easy optimization would be to re-use the same URI for each watcher so that the calls to fsPath are shared. Looks like we do create a new URI for each handler over and over:

for (const created of events.created) {
const uri = URI.revive(created);
if (parsedPattern(uri.fsPath) && (!excludeOutOfWorkspaceEvents || workspace.getWorkspaceFolder(uri))) {
this._onDidCreate.fire(uri);
}
}

@bpasero bpasero added this to the October 2023 milestone Oct 3, 2023
@bpasero bpasero added the extension-host Extension host issues label Oct 3, 2023
@jrieken
Copy link
Member

jrieken commented Oct 3, 2023

All optimisations aside we can always have a case in which it is just too much. So, in addition to perf fixes we should emit the events in smaller chunks and "pause" in-between

@bpasero
Copy link
Member

bpasero commented Oct 3, 2023

Opened #194697 to re-use Uri and not revive it per-watcher, so that only the first user of .fsPath triggers the compute. Maybe in this setup here there are tens or hundreds of file system watchers created by the extension?

We do throttle file events since a long time given other similar issues:

private readonly throttledFileChangesEmitter = this._register(new ThrottledWorker<IDiskFileChange>(
{
maxWorkChunkSize: 500, // only process up to 500 changes at once before...
throttleDelay: 200, // ...resting for 200ms until we process events again...
maxBufferedWork: 30000 // ...but never buffering more than 30000 events in memory
},
events => this._onDidChangeFile.fire(events)
));

This throttling happens at the source where we receive them from parcel-watcher. We do add a warning to the logs in case events are throttled. @lifengl can you maybe share your VS Code logs to use so that I can try to find it?

@jrieken
Copy link
Member

jrieken commented Oct 3, 2023

This throttling happens at the source where we receive them from parcel-watcher. We do add a warning to the logs in case events are throttled.

I that case I wonder why the EH stops responding. If the chunks are overly large and the machines not overly slow nothing should be blocked but saturated.

@jrieken
Copy link
Member

jrieken commented Oct 3, 2023

Opened #194697 to re-use Uri and not revive it per-watcher, so that only the first user of .fsPath triggers the compute. Maybe in this setup here there are tens or hundreds of file system watchers created by the extension?

That's a good change but I doubt the extension has very many file watchers.

I am still wondering if we can avoid using and computing fsPath to begin with. Can't the glob matcher know cases when it doesn't matter? Like all *.SUFFIX or **/*.SUFFIX don't need an uri authority, right?

@jrieken
Copy link
Member

jrieken commented Oct 3, 2023

Alternative trick/hack to avoid recomputing fsPath is to trigger its computation in the file watching process. That will populate the property and make it part of the toJSON and revive cycle. Also the renderer, which likely also does glob matching, could benefit from that

@bpasero
Copy link
Member

bpasero commented Oct 3, 2023

I am still wondering if we can avoid using and computing fsPath to begin with. Can't the glob matcher know cases when it doesn't matter? Like all .SUFFIX or **/.SUFFIX don't need an uri authority, right?

I had thought about it, in the end what we really want is Uri support in Glob to defer .fsPath compute as much as possible. We just do not have that capability today.

Alternative trick/hack to avoid recomputing fsPath is to trigger its computation in the file watching process. That will populate the property and make it part of the toJSON and revive cycle. Also the renderer, which likely also does glob matching, could benefit from that

I like

@bpasero
Copy link
Member

bpasero commented Oct 4, 2023

@jrieken #194774 makes that happen. I wonder if UriComponents could become a smaller object on macOS and Linux where path is always (?) the same as fsPath:

image

Maybe when toJSON, we could check if path === fsPath and then drop the fsPath property?

bpasero added a commit that referenced this issue Oct 4, 2023
…n host (for #194341) (#194697)

* file watcher - reuse instances of `Uri` in event handlers in extension host (for #194341)

* feedback: save a function call

* use `Lazy`
@bpasero
Copy link
Member

bpasero commented Oct 5, 2023

@lifengl given we fixed this perf issue in insiders, can you try again with insiders and see how performance is for you now?

Can you try to reproduce with our nightly insider builds? You can give our preview releases a try from: https://code.visualstudio.com/insiders/

@jrieken
Copy link
Member

jrieken commented Oct 5, 2023

Maybe when toJSON, we could check if path === fsPath and then drop the fsPath property?

I kinda like but dropping would trigger a recompute on the receiving side... It would need some other mechanism

bpasero added a commit that referenced this issue Oct 10, 2023
* watcher - emit `URI` instead of `string` for faster `fsPath` compute  (for #194341)

* wip

* more

* adopt

* some cleanup

* cleanup

* cleanup

* cleanup

* cleanup

* cleanup

* cleanup

* implement correlation

* cleanup

* add correlation

* undo, leave for later

* tests

* tests

* tests

* tests

* tests

* log cId

* simpler correlation id

* 💄

* tests

* runs

* skip normalization

* fix tests

* tests

* fix tests

* add `createWatcher` API

* partition events in ext host

* allow custom excludes

* remove disk file change

* 💄

* 💄

* 💄

* wire in

* wire in
@bpasero bpasero closed this as completed Oct 11, 2023
@bpasero
Copy link
Member

bpasero commented Oct 11, 2023

Closing until we hear otherwise.

Alex0007 pushed a commit to Alex0007/vscode that referenced this issue Oct 26, 2023
…n host (for microsoft#194341) (microsoft#194697)

* file watcher - reuse instances of `Uri` in event handlers in extension host (for microsoft#194341)

* feedback: save a function call

* use `Lazy`
Alex0007 pushed a commit to Alex0007/vscode that referenced this issue Oct 26, 2023
* watcher - emit `URI` instead of `string` for faster `fsPath` compute  (for microsoft#194341)

* wip

* more

* adopt

* some cleanup

* cleanup

* cleanup

* cleanup

* cleanup

* cleanup

* cleanup

* implement correlation

* cleanup

* add correlation

* undo, leave for later

* tests

* tests

* tests

* tests

* tests

* log cId

* simpler correlation id

* 💄

* tests

* runs

* skip normalization

* fix tests

* tests

* fix tests

* add `createWatcher` API

* partition events in ext host

* allow custom excludes

* remove disk file change

* 💄

* 💄

* 💄

* wire in

* wire in
@github-actions github-actions bot locked and limited conversation to collaborators Nov 25, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
extension-host Extension host issues file-watcher File watcher freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues info-needed Issue requires more information from poster
Projects
None yet
Development

No branches or pull requests

5 participants