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

Completions stop working during heavy usage #3009

Closed
chris-armstrong opened this issue Jan 19, 2021 · 8 comments
Closed

Completions stop working during heavy usage #3009

chris-armstrong opened this issue Jan 19, 2021 · 8 comments
Labels
A-extension Area: Extension/plugin integration, vscode or VimL bug Something isn't working I-daily-editor-blocker An issue blocking use of the editor as a day-to-day editor

Comments

@chris-armstrong
Copy link

I'm using Onivim2 as my day-to-day editor (it's pretty good!), and a recurrent problem I'm finding is that the completion suggestions will stop working at some point after starting it up, requiring a restart of Onivim2 to get them working again. I've tried executing the 'Typescript: Restart TS Server' option, but this doesn't seem to work.

I'm running completions on TypeScript files. I ran onivim2 with logging enabled, and found this at the time of its failure which suggestions the VSCode extension host died:

[INFO]  [1345.894s] Exthost.Transport : Connection closed.
[WARN]  [1345.894s] Exthost.Client : Unhandled message: Exthost_Protocol.Message.Incoming.Disconnected
[INFO]  [1345.895s] Oni2.Extension.ClientStore : Extension host process exited with exit status: 0 and signal: 6
[INFO]  [1345.896s] Oni2.Store.dispatch : dispatch: KeyboardInput {isText = false; input = "<BS>"}
[INFO]  [1345.897s] Oni2.Store.dispatch : dispatch: (LanguageSupport (Feature_LanguageSupport.Hover (KeyPressed "<BS>")))
[INFO]  [1345.897s] Oni2.Store.dispatch : dispatch: (Buffers
   Update {update = <opaque>; oldBuffer = <opaque>; newBuffer = <opaque>;
     triggerKey = (Some "<BS>")})
[INFO]  [1345.898s] Oni2.Store.dispatch : dispatch: (Vim
   Feature_Vim.ModeChanged {allowAnimation = true; mode = <opaque>;
     subMode = <opaque>; effects = <opaque>})
[ERROR] [1345.914s] Oni2.Extension.ClientStore : Stream.write: bad file descriptor

The last error, Stream.write bad file descriptor continues to occur after this point (I could find no instances of it before).

I know this only suggests the extension host received a SIGABRT (maybe an out of memory condition?), so I realise I'll probably have to dig deeper. Can anyone suggest how I might capture some more information about the extension host connection or from the extension host itself to debug this, or any other pointers?

@bryphe bryphe added bug Something isn't working I-daily-editor-blocker An issue blocking use of the editor as a day-to-day editor A-extension Area: Extension/plugin integration, vscode or VimL labels Jan 19, 2021
@bryphe
Copy link
Member

bryphe commented Jan 19, 2021

Thanks for logging the issue @chris-armstrong and grabbing the logs!

using Onivim2 as my day-to-day editor (it's pretty good!)

This is great to hear 😄 Sounds like you're exercising it thoroughly.

I know this only suggests the extension host received a SIGABRT (maybe an out of memory condition?), so I realise I'll probably have to dig deeper.

I believe your assessment is accurate - my suspicion is that we're hitting the heap memory limit of Node (suggesting some memory leak). Another possibility is we're hitting the open file descriptor limit. I'm going to take a look and see if I see anything odd in the memory profiler.

Some extra data points that might be helpful:

  • What version of Onivim were you running? The 0.5.2 stable, or the nightly build?
  • What platform are you running on? Windows, Linux, OSX?

Also I've upgraded our Node version for the extension host in #3012 - Node 12 -> 14 goes from the v8 Javascript engine version v7.x to v8.x (with several performance improvements), but I don't think this is the root issue.

@chris-armstrong
Copy link
Author

chris-armstrong commented Jan 19, 2021 via email

@bryphe
Copy link
Member

bryphe commented Jan 19, 2021

Definitely - we can actually run the node debug tools - if you do the following:

  1. Open Activity Monitor to get the PID of the extension host process:

Screen Shot 2021-01-19 at 2 08 29 PM

  1. Run node debug -p <process id>

  2. Open up Chrome and go to chrome://inspect'

That should show the extension host process available for inspection:

Screen Shot 2021-01-19 at 2 11 21 PM

And then we can use the performance profiling / memory allocation tools:

image

I do think there may be a memory leak in the completions or signature help that could be getting us into this state - when I run the profiler I'm seeing some retained objects there:
image

bryphe added a commit that referenced this issue Jan 19, 2021
Pick up some performance improvements from node v12 -> node v14 for the extension host (notably, updating v8 from v7.x to v8.x)

Prompted by #3009 

__TODO:__
- [x] Upgrade vendored node 14 on Windows
- [x] Upgrade vendored node 14 on OSX
@chris-armstrong
Copy link
Author

chris-armstrong commented Jan 19, 2021 via email

@bryphe
Copy link
Member

bryphe commented Jan 19, 2021

@chris-armstrong - ah, nice investigation, thanks for profiling too! I was thinking the same thing. We're missing those $release* APIs which are needed to clean up the _cached suggest items. Working on a fix in #3016

Looks like the signature help / codelens may also be affected

@chris-armstrong
Copy link
Author

Thanks! Looking forward to the fix for this, apart from buggy vim-surround support, this is probably the main blocker for me day-to-day with Onivim2

bryphe added a commit that referenced this issue Jan 20, 2021
…cache (#3016)

__Issue:__ There is a memory leak in our completion items, signature help, and codelens via the extension host - may be responsible for the `SIGABRT` described in #3009 (as this can occur when the JS heap is out of memory).

__Defect:__ The extension host adds a layer on top of the language server protocol, to serve as a cache for several language features - this helps performance when resolving items. However, this caching layer relies on the client to notify it when the items are no longer in use, so they can be cleaned up. Onivim was missing this `release` step.

__Fix:__ Bake in the call to `release` in all the relevant subscriptions. This involves picking up the `cacheId` which wasn't wired up in some places (like codelens), setting up the `release*` API, and passing it back on conclusion of the subscription.


To test this fix - I flipped the `Cache.enableDebugLogging` flag in the extension host and initiated several completions. Before this fix, it's obvious the caches were simply growing endlessly:
```
CompletionItem cache size — 1
CompletionItem cache size — 1
CompletionItem cache size — 2
CompletionItem cache size — 2
SignatureHelp cache size — 1
CompletionItem cache size — 3
CompletionItem cache size — 3
CompletionItem cache size — 4
CompletionItem cache size — 4
SignatureHelp cache size — 2
...
CompletionItem cache size — 15
CompletionItem cache size — 15
CompletionItem cache size — 16
CompletionItem cache size — 16
CompletionItem cache size — 17
CompletionItem cache size — 17
SignatureHelp cache size — 8
CompletionItem cache size — 18
CompletionItem cache size — 18
CompletionItem cache size — 19
CompletionItem cache size — 19
```

After this fix, though, we can observe that the cache gets cleaned:
```
CompletionItem cache size — 1
CompletionItem cache size — 1
CompletionItem cache size — 0
CompletionItem cache size — 0
CompletionItem cache size — 1
CompletionItem cache size — 1
CompletionItem cache size — 0
CompletionItem cache size — 0
SignatureHelp cache size — 1
SignatureHelp cache size — 0

...
CompletionItem cache size — 0
CompletionItem cache size — 0
SignatureHelp cache size — 1
SignatureHelp cache size — 0
```

Related #3009 
Related #1058
@chris-armstrong
Copy link
Author

This is behaving so much better now that the #3016 fix is in. I've profiled it again and the memory usage is much more stable and not growing.

Happy for this to be closed.

@bryphe
Copy link
Member

bryphe commented Jan 21, 2021

Awesome news! Thanks for the update and all your help investigating @chris-armstrong - I'll close this out!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-extension Area: Extension/plugin integration, vscode or VimL bug Something isn't working I-daily-editor-blocker An issue blocking use of the editor as a day-to-day editor
Projects
None yet
Development

No branches or pull requests

2 participants