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.

[dbaeumer]

@DonJayamanne I did some more testing and I am under the impression that the number of events I get is proportional to the number of cells in the document. A notebook document with 3 code cells sends out 18 NotebookDocumentChangeEvent. This means that for a notebook document with 500 cells we have 3000 of these events.

Why are these event not batch, especially since NotebookDocumentChangeEvent has a list of contentChanges and a list of cellChanges which can list all cells that have changed.?

I am not saying that the code in ESLint can't be optimized. I am always for performance improvements. But executing a notebook with 500 cells shouldn't generate more events than executing a notebook document with one cell. If we can minimize the number of events all listeners for NotebookDocumentChangeEvent will profit from this.

Adding @roblourens @rebornix since IMO this is nothing that can only be addressed by ESLint. Another listener or extension can cause the same performance problem without knowing.

What would definitely help as well is some reason in the event, especially when the event is fired because of cell execution start execution, set execution order clear output, ...

Then listeners could ignore some of these event without the need of inspecting their data.

[rebornix]

@dbaeumer thanks for digging into this and the feedbacks.!

I am under the impression that the number of events I get is proportional to the number of cells in the document

Right, it's proportional to the cell count. It's the nature of notebooks, which are multi-documents-y, like a workspace/project.

Why are these event not batch, especially since NotebookDocumentChangeEvent has a list of contentChanges and a list of cellChanges which can list all cells that have changed.?

I think we designed this in the same fashion as text document change events. Content change events are not delayed, when the core receives a change, it emits it to EH and broadcasts to all listeners.

For example, when I press enter in TS file, I got four events (first event is the change, and I don't understand the other 3, maybe some format/indent/codeaction)

And if I try to F2 to rename a symbol, which touches two files, I got 8 events, which is proportional to the amount of files touched.

This is the same reason why executing 500 cells emit 500*N events, as cells run in sequence, and we don't have any "debouncing" for the events.

---

With that said, @DonJayamanne and I discussed about if we can debounce the events, but that's a breaking behavior change and I'm also concerned that it might lead to unexpected issues for extensions.

What would definitely help as well is some reason in the event, especially when the event is fired because of cell execution start execution, set execution order clear output, ...

This is a really great idea and I think we should add reason to NotebookDocumentChangeEvent, similar to TextDocumentChangeEvent#reason. With this info, we could filter out most events in the language server client so extensions like ESLint don't need to do the filtering themselves by checking the content of each event.

[dbaeumer]

I thought about it a little more but I am still a little afraid about the number of events, especially I don't see what a extension should do with all of them. I debugged the events with a notebook with one cell so my statements might be incorrect. And I discovered the following things:

• event one and two are identical; may be we can remove one of it.
• could we fold five and six into one event.
• could we fold three and four. Here I am even myself skeptical if it is a good idea, especially if execution fails.

I have attached the debugger output of all six events.

And sorry for bothering you with that but the less events we sent the less damage badly written extensions can cause.

[DonJayamanne]

Issue that would help with the events #212063

[DonJayamanne]

I think we’ve addressed all the issues in waking and core
Hence closing this