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

Labels service leaks listeners in emmet integration tests #119968

Closed
connor4312 opened this issue Mar 26, 2021 · 14 comments
Closed

Labels service leaks listeners in emmet integration tests #119968

connor4312 opened this issue Mar 26, 2021 · 14 comments
Assignees
Labels
freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues workbench-editors Managing of editor widgets in workbench window
Milestone

Comments

@connor4312
Copy link
Member

While checking #116775, I noticed another leak which looks like it's coming from here:

this._register(this.modeService.onLanguagesMaybeChanged(() => this.widgets.forEach(widget => widget.notifyExtensionsRegistered())));

2021-03-26T13:25:15.0689588Z [3732:0326/132514.638:INFO:CONSOLE(366)] "[cbe] potential listener LEAK detected, having 175 listeners already. MOST frequent listener (1):", source: file:///D:/a/vscode/vscode/out/vs/base/common/event.js (366)
2021-03-26T13:25:15.3416079Z [3732:0326/132514.638:INFO:CONSOLE(367)] "    at ResourceLabel.registerListeners (file:///D:/a/vscode/vscode/out/vs/workbench/browser/labels.js:53:45)
2021-03-26T13:25:15.8222962Z     at new ResourceLabels (file:///D:/a/vscode/vscode/out/vs/workbench/browser/labels.js:45:18)
2021-03-26T13:25:15.8229698Z     at new ResourceLabel (file:///D:/a/vscode/vscode/out/vs/workbench/browser/labels.js:151:13)
2021-03-26T13:25:15.8234242Z     at InstantiationService._createInstance (file:///D:/a/vscode/vscode/out/vs/platform/instantiation/common/instantiationService.js:89:20)
2021-03-26T13:25:15.8240358Z     at InstantiationService.createInstance (file:///D:/a/vscode/vscode/out/vs/platform/instantiation/common/instantiationService.js:60:31)
2021-03-26T13:25:15.8250874Z     at FileItem.render (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/breadcrumbsControl.js:87:52)
2021-03-26T13:25:15.8265336Z     at BreadcrumbsWidget._renderItem (file:///D:/a/vscode/vscode/out/vs/base/browser/ui/breadcrumbs/breadcrumbsWidget.js:257:22)
2021-03-26T13:25:16.2327058Z     at BreadcrumbsWidget._render (file:///D:/a/vscode/vscode/out/vs/base/browser/ui/breadcrumbs/breadcrumbsWidget.js:231:22)
2021-03-26T13:25:17.9332466Z     at BreadcrumbsWidget.setItems (file:///D:/a/vscode/vscode/out/vs/base/browser/ui/breadcrumbs/breadcrumbsWidget.js:216:22)
2021-03-26T13:25:17.9849237Z     at updateBreadcrumbs (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/breadcrumbsControl.js:186:30)
2021-03-26T13:25:17.9864177Z     at BreadcrumbsControl.update (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/breadcrumbsControl.js:191:13)
2021-03-26T13:25:17.9884195Z     at TabsTitleControl.openEditor (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/tabsTitleControl.js:265:84)
2021-03-26T13:25:17.9893464Z     at EditorGroupView.doShowEditor (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/editorGroupView.js:754:35)
2021-03-26T13:25:17.9930833Z     at EditorGroupView.doOpenEditor (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/editorGroupView.js:720:43)
2021-03-26T13:25:17.9939471Z   170 passing (45s)
2021-03-26T13:25:17.9940923Z     at EditorGroupView.openEditor (file:///D:/a/vscode/vscode/out/vs/workbench/browser/parts/editor/editorGroupView.js:654:64)
2021-03-26T13:25:17.9946230Z     at EditorService.openEditor (file:///D:/a/vscode/vscode/out/vs/workbench/services/editor/browser/editorService.js:453:77)
2021-03-26T13:25:17.9955967Z     at MainThreadTextEditors.$tryShowTextDocument (file:///D:/a/vscode/vscode/out/vs/workbench/api/browser/mainThreadEditors.js:113:54)
2021-03-26T13:25:17.9991898Z     at RPCProtocol._doInvokeHandler (file:///D:/a/vscode/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:348:27)
2021-03-26T13:25:17.9996721Z     at RPCProtocol._invokeHandler (file:///D:/a/vscode/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:333:45)
2021-03-26T13:25:18.0008219Z     at RPCProtocol._receiveRequest (file:///D:/a/vscode/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:260:32)
2021-03-26T13:25:18.0010768Z     at RPCProtocol._receiveOneMessage (file:///D:/a/vscode/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:188:26)
2021-03-26T13:25:18.0012831Z     at file:///D:/a/vscode/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:69:52
2021-03-26T13:25:18.0014606Z     at Emitter.fire (file:///D:/a/vscode/vscode/out/vs/base/common/event.js:479:38)
2021-03-26T13:25:18.0016996Z     at BufferedEmitter.fire (file:///D:/a/vscode/vscode/out/vs/base/parts/ipc/common/ipc.net.js:375:35)
2021-03-26T13:25:18.0029429Z     at PersistentProtocol._receiveMessage (file:///D:/a/vscode/vscode/out/vs/base/parts/ipc/common/ipc.net.js:654:41)
2021-03-26T13:25:18.0097268Z     at file:///D:/a/vscode/vscode/out/vs/base/parts/ipc/common/ipc.net.js:510:83
2021-03-26T13:25:18.0128736Z     at Emitter.fire (file:///D:/a/vscode/vscode/out/vs/base/common/event.js:479:38)
2021-03-26T13:25:18.0132810Z     at ProtocolReader.acceptChunk (file:///D:/a/vscode/vscode/out/vs/base/parts/ipc/common/ipc.net.js:189:37)
2021-03-26T13:25:18.0134626Z     at file:///D:/a/vscode/vscode/out/vs/base/parts/ipc/common/ipc.net.js:158:61
2021-03-26T13:25:18.0136245Z     at Socket.listener (file:///D:/a/vscode/vscode/out/vs/base/parts/ipc/node/ipc.net.js:33:40)
2021-03-26T13:25:18.0139336Z     at Socket.emit (events.js:315:20)
2021-03-26T13:25:18.0140660Z     at addChunk (_stream_readable.js:295:12)
2021-03-26T13:25:18.0141774Z     at readableAddChunk (_stream_readable.js:271:9)
2021-03-26T13:25:18.0144521Z     at Socket.Readable.push (_stream_readable.js:212:10)
2021-03-26T13:25:18.0146566Z     at Pipe.onStreamRead (internal/stream_base_commons.js:186:23)", source: file:///D:/a/vscode/vscode/out/vs/base/common/event.js (367)
2021-03-26T13:25:18.5344169Z yarn run v1.22.10
2021-03-26T13:25:18.6223094Z $ node build/lib/electron
2021-03-26T13:25:19.0531321Z Done in 0.55s.
2021-03-26T13:25:20.1339950Z 
2021-03-26T13:25:20.2864269Z Found --crash-reporter-directory argument. Setting crashDumps directory to be 'D:\a\vscode\vscode\.build\crashes'
2021-03-26T13:25:21.3047035Z (node:6376) electron: The default of contextIsolation is deprecated and will be changing from false to true in a future release of Electron.  See https://github.com/electron/electron/issues/23506 for more information
2021-03-26T13:25:24.9227274Z (node:6376) electron: The default of contextIsolation is deprecated and will be changing from false to true in a future release of Electron.  See https://github.com/electron/electron/issues/23506 for more information
2021-03-26T13:25:25.7940954Z [6376:0326/132524.961:INFO:CONSOLE(632)
@bpasero
Copy link
Member

bpasero commented Mar 29, 2021

I can reproduce and this seems to originate from BreadcrumbsWidget @jrieken. Though I am not sure this is actually a leak or just the fact that the emmet integration tests open so many editors during the run.

I noticed that the emmet tests did not properly close editors on teardown and pushed b19f50e as a fix.

Anyhow, should revisit the dispose is properly called for breadcrumb helpers such as FileItem.

@bpasero bpasero changed the title Labels service leaks listeners in test Labels service leaks listeners in emmet integration tests Mar 29, 2021
@jrieken
Copy link
Member

jrieken commented Mar 29, 2021

MOST frequent listener (1):",

The (1) means that there most frequent stacktrace occurs once. So, I doubt that this is a leak

@bpasero
Copy link
Member

bpasero commented Mar 29, 2021

I also played around with some ref counting of FileItem and did not see a leak opening and closing editors.

@jrieken should we maybe not print any exception if the most recent stack is (1) indicating that there is probably no leak?

@jrieken
Copy link
Member

jrieken commented Mar 29, 2021

not print any exception if the most recent stack is (1) indicating that there is probably no leak?

idk - I think there is still value. Even tho, there are many, many individual listener we should take it as sign of a problem. In this case we should ask ourself if we really want hundreds or thousands of editors open at the same time

@bpasero
Copy link
Member

bpasero commented Mar 29, 2021

@jrieken they are opened but also closed, at least visually I see just always 1 editor open. There are hundreds of editors opened and closed in a very short timeframe, which probably causes breadcrumbs to update a ton. At least for tabs they always share the same resource label, so that might explain why there is no warning for tabs.

Agree it would be interesting if some cleanup is missing in the test run at least.

@bpasero bpasero added this to the April 2021 milestone Mar 29, 2021
@bpasero
Copy link
Member

bpasero commented Mar 29, 2021

This is very very bizarre. Commenting out just this line makes the exception go away:

this._register(this.modeService.onLanguagesMaybeChanged(() => this.widgets.forEach(widget => widget.notifyExtensionsRegistered())));

In other words, I verified that the FileLabel gets disposed properly, otherwise all the other listeners in ResourceLabels would show an error too.

@jrieken I am clueless why this one listener would result in the error, it looks like a very normal Event like the others, such as this one which is also not causing any error to be printed? Do you have an idea?

this._register(this.modelService.onModelModeChanged(e => {

@bpasero
Copy link
Member

bpasero commented Mar 29, 2021

Hm, maybe this is a red herring and this is just the last listener that is causing the error to print but otherwise being unrelated...

@bpasero bpasero added freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues workbench-editors Managing of editor widgets in workbench window and removed breadcrumbs labels Mar 29, 2021
@bpasero
Copy link
Member

bpasero commented Mar 29, 2021

Wow, an actual leak. I didn't know that ILanguageSelection is disposable!

this._register(onLanguagesMaybeChanged(() => this._evaluate()));

@bpasero
Copy link
Member

bpasero commented Mar 30, 2021

@alexdima I think the concept of LanguageSelection came in via 44a8080#diff-6b0324a9b2e122283182cacbd5f53b0add5387c5b9a8f51b48c4cf1daa84bac9 a while ago and you have to help me understand how to use it.

It seems to me that we now often have code like this:

const languageSelection = this.modeService.create('jsonc');
const model = this._register(this.modelService.createModel('', languageSelection, uri));

Another example in notebook land:

const language = cell.cellKind === CellKind.Markdown ? this._modeService.create('markdown') : (cell.language ? this._modeService.create(cell.language) : this._modeService.createByFilepathOrFirstLine(resource, cell.textBuffer.getLineContent(1)));
result = this._modelService.createModel(
bufferFactory,
language,
resource
);

Where we first create the languageSelection and then pass it into the model (via createModel).

Should the calls that create the ILanguageSelection do the disposing of it? I think that needs a wider adoption then for anyone calling any of these methods:

  • IModeService#create
  • IModeService#createByLanguageName
  • IModeService#createByFilepathOrFirstLine

@bpasero bpasero changed the title Labels service leaks listeners in emmet integration tests Creators of ILanguageSelection are not dipsosing it Mar 31, 2021
@alexdima alexdima changed the title Creators of ILanguageSelection are not dipsosing it Labels service leaks listeners in emmet integration tests Apr 1, 2021
@alexdima
Copy link
Member

alexdima commented Apr 1, 2021

@bpasero I have pushed a fix for the ILanguageSelection via 4cd94d0

Even with this fix, when I execute the emmet tests I still see the leakage warning initially reported. So I don't believe that was the root cause here. I am leaving the issue open for you to decide what to do:

[93e] potential listener LEAK detected, having 175 listeners already. MOST frequent listener (1):
    at ResourceLabel.registerListeners (file:///Users/alex/src/vscode/out/vs/workbench/browser/labels.js:53:45)
    at new ResourceLabels (file:///Users/alex/src/vscode/out/vs/workbench/browser/labels.js:45:18)
    at new ResourceLabel (file:///Users/alex/src/vscode/out/vs/workbench/browser/labels.js:151:13)
    at InstantiationService._createInstance (file:///Users/alex/src/vscode/out/vs/platform/instantiation/common/instantiationService.js:89:20)
    at InstantiationService.createInstance (file:///Users/alex/src/vscode/out/vs/platform/instantiation/common/instantiationService.js:60:31)
    at FileItem.render (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/breadcrumbsControl.js:87:52)
    at BreadcrumbsWidget._renderItem (file:///Users/alex/src/vscode/out/vs/base/browser/ui/breadcrumbs/breadcrumbsWidget.js:262:22)
    at BreadcrumbsWidget._render (file:///Users/alex/src/vscode/out/vs/base/browser/ui/breadcrumbs/breadcrumbsWidget.js:236:22)
    at BreadcrumbsWidget.setItems (file:///Users/alex/src/vscode/out/vs/base/browser/ui/breadcrumbs/breadcrumbsWidget.js:221:22)
    at updateBreadcrumbs (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/breadcrumbsControl.js:199:34)
    at BreadcrumbsControl.update (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/breadcrumbsControl.js:205:13)
    at TabsTitleControl.openEditor (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/tabsTitleControl.js:265:84)
    at EditorGroupView.doShowEditor (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/editorGroupView.js:747:35)
    at EditorGroupView.doOpenEditor (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/editorGroupView.js:713:43)
    at EditorGroupView.openEditor (file:///Users/alex/src/vscode/out/vs/workbench/browser/parts/editor/editorGroupView.js:647:25)
    at EditorService.openEditor (file:///Users/alex/src/vscode/out/vs/workbench/services/editor/browser/editorService.js:453:38)
    at MainThreadTextEditors.$tryShowTextDocument (file:///Users/alex/src/vscode/out/vs/workbench/api/browser/mainThreadEditors.js:113:54)
    at RPCProtocol._doInvokeHandler (file:///Users/alex/src/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:348:27)
    at RPCProtocol._invokeHandler (file:///Users/alex/src/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:333:45)
    at RPCProtocol._receiveRequest (file:///Users/alex/src/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:260:32)
    at RPCProtocol._receiveOneMessage (file:///Users/alex/src/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:188:26)
    at file:///Users/alex/src/vscode/out/vs/workbench/services/extensions/common/rpcProtocol.js:69:52
    at Emitter.fire (file:///Users/alex/src/vscode/out/vs/base/common/event.js:479:38)
    at BufferedEmitter.fire (file:///Users/alex/src/vscode/out/vs/base/parts/ipc/common/ipc.net.js:375:35)
    at PersistentProtocol._receiveMessage (file:///Users/alex/src/vscode/out/vs/base/parts/ipc/common/ipc.net.js:654:41)
    at file:///Users/alex/src/vscode/out/vs/base/parts/ipc/common/ipc.net.js:510:83
    at Emitter.fire (file:///Users/alex/src/vscode/out/vs/base/common/event.js:479:38)
    at ProtocolReader.acceptChunk (file:///Users/alex/src/vscode/out/vs/base/parts/ipc/common/ipc.net.js:189:37)
    at file:///Users/alex/src/vscode/out/vs/base/parts/ipc/common/ipc.net.js:158:61
    at Socket.listener (file:///Users/alex/src/vscode/out/vs/base/parts/ipc/node/ipc.net.js:33:40)
    at Socket.emit (events.js:315:20)
    at addChunk (_stream_readable.js:295:12)
    at readableAddChunk (_stream_readable.js:271:9)
    at Socket.Readable.push (_stream_readable.js:212:10)
    at Pipe.onStreamRead (internal/stream_base_commons.js:186:23)

@alexdima alexdima removed their assignment Apr 1, 2021
@bpasero
Copy link
Member

bpasero commented Apr 5, 2021

@alexdima I think there is still a leak, trying to find it I added a trace to the first listener that gets added to LanguageSelection and it seems to be this ModelData.setLanguage call:

at Object.onFirstListenerAdd (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/editor/common/services/modeServiceImpl.js:16:52)
    at LanguageSelection._event [as onDidChange] (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/base/common/event.js:417:39)
    at ModelData.setLanguage (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/editor/common/services/modelServiceImpl.js:53:71)
    at ModelServiceImpl.setMode (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/editor/common/services/modelServiceImpl.js:378:23)
    at ModelServiceImpl.createModel (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/editor/common/services/modelServiceImpl.js:362:22)
    at TextFileEditorModel.doCreateTextEditorModel (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/common/editor/textEditorModel.js:79:43)
    at TextFileEditorModel.createTextEditorModel (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/common/editor/textEditorModel.js:74:25)
    at TextFileEditorModel.doCreateTextModel (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/services/textfile/common/textFileEditorModel.js:387:36)
    at TextFileEditorModel.resolveFromContent (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/services/textfile/common/textFileEditorModel.js:373:22)
    at TextFileEditorModel.resolveFromFile (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/services/textfile/common/textFileEditorModel.js:315:29)
    at async TextFileEditorModelManager.resolve (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/services/textfile/common/textFileEditorModelManager.js:261:17)
    at async TextModelResolverService.createModelReference (vscode-file://vscode-app/Users/bpasero/Development/Microsoft/monaco/out/vs/workbench/services/textmodelResolver/common/textModelResolverService.js:160:31)

So it seems that ModelData needs to be disposed properly. Looking at creators of ModelData, it is not clear to me how I can dispose it:

Can you advise?

@alexdima
Copy link
Member

alexdima commented Apr 6, 2021

@bpasero What steps should I take to observe a leak? ModelData is disposed here.

@bpasero
Copy link
Member

bpasero commented Apr 6, 2021

@alexdima nevermind, I figured out the root cause: we use this method to open a random file for integration tests:

export function withRandomFileEditor(initialContents: string, fileExtension: string = 'txt', run: (editor: vscode.TextEditor, doc: vscode.TextDocument) => Thenable<void>): Thenable<boolean> {

Which I think is fair, given the API tests only have access to our API. However, this ends up calling openTextDocument which will result in a model reference getting created for text file models. A second reference is created from the text editor itself upon resolving. When the editor closes, we dispose that reference but we do not dispose the one from openTextDocument at the end of the test and as such we "leak" these models at least for a moment.

I think @jrieken has reasons for this, I recall there is a timeout when we GC text file model references with the rationale that we are not giving extensions anyway to dispose those models explicitly.

I pushed a change to increase the threshold for leaking in this one listener but it feels a bit like a workaround / bandaid:

protected readonly _onLanguagesMaybeChanged = this._register(new Emitter<void>({ leakWarningThreshold: 200 /* https://github.com/microsoft/vscode/issues/119968 */ }));

Up to you and maybe Jo to decide if a different fix is needed, but I think this is just how our API works today and the integration tests manage to hit this warning because they open >175 editors in a very short period of time.

@jrieken
Copy link
Member

jrieken commented Apr 6, 2021

I recall there is a timeout when we GC text file model references with the rationale that we are not giving extensions anyway to dispose those models explicitly.

Yes - there is a timeout and total size limit

@bpasero bpasero closed this as completed Apr 6, 2021
@github-actions github-actions bot locked and limited conversation to collaborators May 21, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
freeze-slow-crash-leak VS Code crashing, performance, freeze and memory leak issues workbench-editors Managing of editor widgets in workbench window
Projects
None yet
Development

No branches or pull requests

4 participants