File watcher creates lag in the terminal

[anavarre]

Bug Description:

Having more than 1 file or directory tracked by the file watcher creates lag when typing in the terminal. Note that the issue with the file system watcher was reported multiple times:

• Is there any way to improve the performance of nsfw watcher? #5897
• [performance] [filesystem] Slow loading with large workspace root #3697

Steps to Reproduce:

1. Create a brand new IDE
2. Observe there is no terminal lag.

Suggestion: hold down a single key on the terminal on 3-4 lines and observe whether the input is constant or has pauses where it stops and then catches up quickly. There should be NO pause or .5 sec max.

Also, you can observe that incoming network traffic briefly stops on the web socket network tab in the Chrome inspector.

3. Open Theia's settings.json via File->Settings->Open Preferences and click on {} to edit the preferences as JSON.
4. Replace (or add) the files.watcherExclude block so it looks like this (which excludes ALL files from the watcher):

"files.watcherExclude": {
  "/**": true
}

6. Reload the Theia browser tab
7. Assuming you have PHP and Composer installed, add files to file system with:

composer create-project acquia/drupal-recommended-project .

As an alternative, the same observation should be possible with a large project with many files and directories...Theia's codebase maybe?

8. Observe there is still no terminal lag.
9. Refresh the Explorer pane with the "Refresh Explorer" icon
10. Observe file tree updates. Still no terminal lag.
11. Revert or remove changes to settings.json.
12. Reload the Theia browser tab
13. Observe terminal lag is now present. Pauses of about 2 seconds, pretty often happening (perhaps 5 times on 4 lines)
14. Revert the reversion. E.g., add back

"files.watcherExclude": {
  "/**": true
}

15. Reload the Theia browser tab
16. Observe lag is still present! Once it’s there, you can’t get rid of it.
17. Now run rm -rf ./* to wipe all files and directories.
18. Lag still present!
19. But if actually if rm -rf .git and reload, then the lag goes away
20. Try to add the following to settings.json

  "files.watcherExclude": {
    "**/.git/objects/**": true,
    "**/.git/subtree-cache/**": true,
    "**/node_modules/**": true
  }

21. Reload the Theia browser tab
22. Observe the lag is still present

So somehow, once the file watcher registers a file, the presence of it will continue to cause lag even when the file watcher is then disabled or updated to be more aggressive with excluding files. You must both disable to file watcher and remove the files to remove the lag.

Additional Information

• Operating System: Ubuntu Xenial (16.04)
• Theia Version: 1.18.0

[vince-fugnitto]

@anavarre given you are on ubuntu, can you confirm how many inotify watchers you have?
It is recommended to increase the count: https://github.com/eclipse-theia/theia/blob/master/doc/Developing.md#linux which may contribute to the lagness you encountered.

[anavarre]

We used to be on Ubuntu's 8192 default. Unrelated to this issue we increased the value to:

test:~/project $ cat /proc/sys/fs/inotify/max_user_watches
524288

It didn't positively affect the behavior.

[vince-fugnitto]

@anavarre can you confirm the issue also exists for the electron (desktop) version. I want to confirm it's actually an issue with file-watchers and not your setup or network.

[anavarre]

I've never tried the desktop version and don't know that we can easily build it to connect to our remote IDEs that are behind OAuth. But to your point:

I want to confirm it's actually an issue with file-watchers and not your setup or network.

It's happening to countless people all around the world (though we're hosted on AWS us-east1), I'm just the messenger here, and was able to reproduce the issue with the steps above.

[grasmash]

I can confirm I'm experiencing this issue too. @vince-fugnitto are there any debugging steps you'd suggest? Any additional info I can provide?

[vince-fugnitto]

I can confirm I'm experiencing this issue too. @vince-fugnitto are there any debugging steps you'd suggest? Any additional info I can provide?

@anavarre @grasmash I don't have any suggestions other than tracing and debugging to see why the watchers would impact the terminal (likely using up the websocket).

I also wanted to mention that the glob will not work to exclude all files:

"files.watcherExclude": {
  "/**": true
}

Will not match for instance resources at the root of the workspace and node_modules/ I believe.

Testing with the base framework (sources) I was not able to reproduce a lag when using the terminal, I wonder if it has to do with the example used and many changes or opened files.

[grasmash]

tracing and debugging to see why the watchers would impact the terminal (likely using up the websocket).

Erm, how does trace and debug a watcher? I'm happy to learn new tools for this. Can you suggest a starting point?

[vince-fugnitto]

Erm, how does trace and debug a watcher? I'm happy to learn new tools for this. Can you suggest a starting point?

The watchers would be debugged on the backend, likely a good place to start would be the following two files:

• https://github.com/eclipse-theia/theia/blob/master/packages/filesystem/src/node/nsfw-watcher/nsfw-filesystem-watcher.ts
• https://github.com/eclipse-theia/theia/blob/master/packages/filesystem/src/node/nsfw-watcher/nsfw-filesystem-service.ts

It should be possible to already set up tracing to see what exactly is going on, and consuming resources that would make the terminal lag in your case.

Also, the following is how files.watcherExclude is read and used to watch the workspace root:

theia/packages/workspace/src/browser/workspace-service.ts

Lines 601 to 620 in 88833b8

	protected async watchRoot(root: FileStat): Promise<void> {
	const uriStr = root.resource.toString();
	if (this.rootWatchers.has(uriStr)) {
	return;
	}
	const excludes = this.getExcludes(uriStr);
	const watcher = this.fileService.watch(new URI(uriStr), {
	recursive: true,
	excludes
	});
	this.rootWatchers.set(uriStr, new DisposableCollection(
	watcher,
	Disposable.create(() => this.rootWatchers.delete(uriStr))
	));
	}
	protected getExcludes(uri: string): string[] {
	const patterns = this.fsPreferences.get('files.watcherExclude', undefined, uri);
	return Object.keys(patterns).filter(pattern => patterns[pattern]);
	}

[grasmash]

So, the lag is very regular. It happens for about 1 second every 5 seconds. I suspect this may be the debounce interval for nsfw. Would it be possible to configure this interval to be longer? If so, what is the best way to pass that configuration to Theia?

[vince-fugnitto]

So, the lag is very regular. It happens for about 1 second every 5 seconds. I suspect this may be the debounce interval for nsfw. Would it be possible to configure this interval to be longer? If so, what is the best way to pass that configuration to Theia?

@grasmash following #7465 (comment) you should be able to pass the options you'd want in a custom extension. It might be good to try!

[grasmash]

Will try. I think this is what I need in a backend module:

import { ContainerModule } from '@theia/core/shared/inversify';
import { NsfwOptions } from '@theia/filesystem/lib/node/nsfw-watcher/nsfw-options';

export default new ContainerModule((bind, unbind, isBound, rebind) => {
  rebind(NsfwOptions).toConstantValue({
    // Change node-sentinel-file-watcher to only check for filesystem changes every 10 seconds.
    debounceMS: 10000
  })
});

[grasmash]

Unfortunately, this is not have the intended effect. I can confirm that I correctly implemented the debounce variable and the file tree updates were delayed by the set amount.

however, the regular lag every five seconds persisted.

[anavarre]

Closing because we have updated 8 versions of Theia and have resolved Kubernetes issues participating in terminal lag, so I don't think there's anything to fix anymore.