Slow notebook execution with eslint enabled

[roblourens]

Testing #210963

Spends a lot of time in the eslint extension... Did something change with the didChangeNotebookDocument event?

vscode-profile-2024-04-23-10-33-17.cpuprofile.zip

[roblourens]

It's faster after disabling eslint, but still slow, spending a lot of time in a handler for that event but in the python extension

Cells executed 952
Output type text
Time spent in VS Code before extension is notified: 1693
Time spent in Extension Host running all cells: 516
Time spent in VS Code updating UI after exection completed: 15499
Time spent in users perspective: 17708

[DonJayamanne]

Did something change with the didChangeNotebookDocument event?
Nothing changed there,

I believe the problem is with the fact that for every cell cell we access the vscode configuration details and thats slow.
I found this in Jupyter extension as well, and ended up caching the configuration details and detecting changes onDidChange... and filtering the change to the specific setting.

I believe the same would apply here as well (insteading of passing the Cell Uri, we can use the notebook Uri as thats common to the notebook).
I.e. I believe the one improvement that can be made in eslint is passing the Uri of the notebook document and caching the config details.

Will try to contribute to eslint.
What was the notebook you were using and what language in the cells?

spending a lot of time in a handler for that event but in the python extension

Please can you share the CPU profile, I didn't come across any issues with Python extension.
Given that we own that I'd like to ensure we make that faster as well.

[DonJayamanne]

Before changes to eslint
Time spent in VS Code updating UI after exection completed: 22256
Time spent in users perspective: 26793

After changes to eslint
Time spent in VS Code updating UI after exection completed: 2368
Time spent in users perspective: 3068

I.e. 10x improvement, from 22s to 2.3s .
microsoft/vscode-eslint#1837

[DonJayamanne]

Todo: why is eslint even triggering when executing cells?

[dbaeumer]

@DonJayamanne I would first like to understand that as well. The code that you optimized should only be trigger when open / closing documents.

Do you have easy steps for me that I can use to reproduce this.

@sandy081 do you know about any performance issues with Workspace.getConfiguration('eslint', textDocument.uri) or config.get. May be it would be worthwhile improving the performance there then instead of caching configurations in extensions.

[DonJayamanne]

The code that you optimized should only be trigger when open / closing documents.

Not true.
Looking at the stack trace, in vscode-languageclient/lib/common/notebook.ts file
https://github.com/microsoft/vscode-languageserver-node/blob/8e625564b531da607859b8cb982abb7cdb2fbe2e/client/src/common/notebook.ts#L606-L641

the didChangeNotebookDocument is triggered when execution information for notebook cells change.
That method then calls the getMatchingCells, which in turn calls filterCells and that calls the filterCells method in eslint which calls the validator.check method which accessEs the configuraiton.

As mentioned here microsoft/vscode-eslint#1837 (comment)
I think the if clause might need some tweeking, as this code is getting executed for python documents.
If the if clause can be tweeked, then the PR would be unnecessary, at least in this context.

[sandy081]

I am not aware of any perf issues with config API. It is sync and we have data cached on ext host.

[dbaeumer]

@DonJayamanne thanks for the pointer. I think I understand why this is happening but fixing it in the ESLint side is IMO not the correct way to do. There could be a second extension which causes the same problems. And according to @sandy081 all the config data is cached and sync.

IMO the fix needs to go into the language server client to fix this for everyone. I will look into using the test plan item to reproduce this. If I need help I will ping you.

[dbaeumer]

@DonJayamanne I was able to reproduce this. But what is strange is the fact the executing the Dummy Execution on a notebook document with 1 code and 1 markdown cell fires the didChangeNotebookDocument event six times. Is this expected? I would have expected that I get one event describing the change of the whole run.

[dbaeumer]

[DonJayamanne]

@dbaeumer Yes this is expected, the changes are for the state transition when executing a cell.

1. Start execution
2. Set execution order
3. Clear output
4. Add an output
5. End execution

& 1 more, I can't remember
Given that these are all separate (& different) method calls, we end up these events.
Generally these events gets fired a few ms to seconds apart depending on how fast the kernel is.
E.g. in Python they can happen within <1s, this dummy extension was created to exclude those delays (from Jupyter extension) so we can see the delays in core and other places.