Completion block any input

[vanarok]

Summary

When using the Ctrl+n/p completion menu only vue files(volar lsp), sometimes the helix (any input) is blocked for a few seconds.

Reproduction Steps

1. Open vue file in helix
2. Use completion(Ctrl+n/p)
   record.webm

Helix log

~/.cache/helix/helix.log

[helix-log.log](https://github.com/helix-editor/helix/files/9992674/helix-log.log)

Platform

Linux

Terminal Emulator

kitty 0.26.5

Helix Version

22.08.1-428-g5b73c8c7

[the-mikedavis]

This looks like a performance problem because of the amount of data that Volar is sending: the completion response is 2.6MB

[vanarok]

Temporary solution: blocking will not happen if you quickly select and close the completion menu.

[sun617]

Have the same problems, it looks like cause by blocking request of completion/resolve.
below is the log, lsp timeout set by 5s

• 1. completion/resolve request sent
• 2. workspace/configuration request sent from server, and before the server response to completion/resolve request,
     it wait for response of workspace/configuration, that result occurs dead lock

2022-11-14T20:58:03.863 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"contentChanges":[{"range":{"end":{"character":6,"line":128},"start":{"character":4,"line":128}},"text":"tagID"}],"textDocument":{"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue","version":4}}}
2022-11-14T20:58:03.868 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":7,"method":"workspace/configuration","params":{"items":[{"section":"volar.diagnostics.delay"}]}}
2022-11-14T20:58:03.886 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null],"id":7}
2022-11-14T20:58:04.262 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"completionItem/resolve","params":{"commitCharacters":[".",",",";","("],"data":{"originalItem":{"commitCharacters":[".",",",";","("],"data":{"fileName":"/home/sun/example/webapp/pages/c/tags/_id.vue.ts","offset":2862,"originalItem":{"kind":"const","kindModifiers":"","name":"tagID","sortText":"11"},"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts"},"insertTextFormat":1,"kind":6,"label":"tagID","sortText":"11","textEdit":{"insert":{"end":{"character":6,"line":86},"start":{"character":4,"line":86}},"newText":"tagID","replace":{"end":{"character":6,"line":86},"start":{"character":4,"line":86}}}},"pluginId":9,"sourceMap":{"embeddedDocumentUri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts"},"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue"},"insertTextFormat":1,"kind":6,"label":"tagID","sortText":"11","textEdit":{"insert":{"end":{"character":6,"line":128},"start":{"character":4,"line":128}},"newText":"tagID","replace":{"end":{"character":6,"line":128},"start":{"character":4,"line":128}}}},"id":3}
2022-11-14T20:58:04.436 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue","diagnostics":[{"range":{"start":{"line":23,"character":21},"end":{"line":23,"character":29}},"severity":1,"source":"ts","code":2531,"message":"Object is possibly 'null'.","data":{"version":4}},{"range":{"start":{"line":128,"character":4},"end":{"line":128,"character":6}},"severity":1,"source":"ts","code":2304,"message":"Cannot find name 'ta'.","data":{"version":4}}],"version":4}}
2022-11-14T20:58:04.438 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":8,"method":"workspace/configuration","params":{"items":[{"scopeUri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts","section":"typescript.format"}]}}
2022-11-14T20:58:04.438 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":9,"method":"workspace/configuration","params":{"items":[{"scopeUri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts","section":"typescript"}]}}
2022-11-14T20:58:04.441 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue","diagnostics":[{"range":{"start":{"line":23,"character":21},"end":{"line":23,"character":29}},"severity":1,"source":"ts","code":2531,"message":"Object is possibly 'null'.","data":{"version":4}},{"range":{"start":{"line":128,"character":4},"end":{"line":128,"character":6}},"severity":1,"source":"ts","code":2304,"message":"Cannot find name 'ta'.","data":{"version":4}}],"version":4}}
2022-11-14T20:58:04.442 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue","diagnostics":[{"range":{"start":{"line":23,"character":21},"end":{"line":23,"character":29}},"severity":1,"source":"ts","code":2531,"message":"Object is possibly 'null'.","data":{"version":4}}],"version":4}}
2022-11-14T20:58:04.442 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue","diagnostics":[{"range":{"start":{"line":23,"character":21},"end":{"line":23,"character":29}},"severity":1,"source":"ts","code":2531,"message":"Object is possibly 'null'.","data":{"version":4}}],"version":4}}
2022-11-14T20:58:09.264 helix_term::ui::completion [ERROR] execute LSP command: request timed out
2022-11-14T20:58:09.278 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null],"id":8}
2022-11-14T20:58:09.279 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null],"id":9}
2022-11-14T20:58:09.279 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":10,"method":"workspace/configuration","params":{"items":[{"scopeUri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts","section":"typescript.preferences"}]}}
2022-11-14T20:58:09.280 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null],"id":10}
2022-11-14T20:58:09.330 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":11,"method":"workspace/configuration","params":{"items":[{"scopeUri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts","section":"typescript.suggest.completeFunctionCalls"}]}}
2022-11-14T20:58:09.331 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null],"id":11}
2022-11-14T20:58:09.332 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":3,"result":{"commitCharacters":[".",",",";","("],"data":{"fileName":"/home/sun/example/webapp/pages/c/tags/_id.vue.ts","offset":2862,"originalItem":{"kind":"const","kindModifiers":"","name":"tagID","sortText":"11"},"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts"},"insertTextFormat":1,"kind":6,"label":"tagID","sortText":"11","textEdit":{"insert":{"start":{"line":128,"character":4},"end":{"line":128,"character":6}},"newText":"tagID","replace":{"start":{"line":128,"character":4},"end":{"line":128,"character":6}}},"detail":"const tagID: string","documentation":{"kind":"markdown","value":""}}}
2022-11-14T20:58:09.332 helix_lsp::transport [INFO] <- {"commitCharacters":[".",",",";","("],"data":{"fileName":"/home/sun/example/webapp/pages/c/tags/_id.vue.ts","offset":2862,"originalItem":{"kind":"const","kindModifiers":"","name":"tagID","sortText":"11"},"uri":"file:///home/sun/example/webapp/pages/c/tags/_id.vue.ts"},"detail":"const tagID: string","documentation":{"kind":"markdown","value":""},"insertTextFormat":1,"kind":6,"label":"tagID","sortText":"11","textEdit":{"insert":{"end":{"character":6,"line":128},"start":{"character":4,"line":128}},"newText":"tagID","replace":{"end":{"character":6,"line":128},"start":{"character":4,"line":128}}}}
2022-11-14T20:58:09.332 helix_lsp::transport [ERROR] Tried sending response into a closed channel (id=Num(3)), original request likely timed out

[the-mikedavis]

I don't think the server is blocking or deadlocked waiting for the response to workspace/configuration. You can see the responses by ID: completionItem/resolve is ID 3 and there are requests and responses to workspace/configuration in between the request and response to resolve.

The request to resolve the completion item does block in helix on the idle-timeout event. That could be refactored to be done asynchronously

[sun617]

• In server view
  It seems(after timeout log 2022-11-14T20:58:09.264) the server wait for response ID 8 and 9 than response ID 3 of completion/resolve
• In helix view
  it blocked on request ID 3, that wait for response ID 3 than response workspace/configuration of ID 8 and 9

[bcspragu]

I've also been experiencing this issue with certain autocompletions in Vue files. The suggestions come up instantly, selecting one causes a ~5+ second hang. Not sure if there's any upstream issues (i.e. in volar) for this, but a 2MB+ payload sounds insane, even for autogenerated typings and whatnot.

Anyway, happy to test any fixes, I can reliably reproduce this.

[the-mikedavis]

Oh I see what you're saying, it does look like we get deadlocked. Resolving the completion item asynchronously should fix this.

[the-mikedavis]

@bcspragu could you give #4781 a try? I think that should fix the deadlock

[bcspragu]

@bcspragu could you give #4781 a try? I think that should fix the deadlock

It 100% does! I'm able to move through completion lists without any problems, and then the actual completion metadata (e.g. type information) shows up a few seconds later. Thanks!

[bcspragu]

I'm not sure if there was a regression somewhere, or if the issue is elsewhere, but I've been hitting this again. More specifically: when I select an autocompletion in a Vue file, sometimes all of Helix will hang for 10-20 seconds.

I don't have a minimum reproducible case as it seems to happen sporadically, but could something recent have caused this?

[gabydd]

#9668 recently changed completion resolution CC: @the-mikedavis and @pascalkuthe

[bcspragu]

That might be too recent to be my issue, looks like I'm running 78c34194, which is a bit older

[pascalkuthe]

we don't resolve anything in the ui loop so I doubt its the same issue. In theory that could be the event system pr but that PR moves even more processing to a background thread so is should have the opposite effect. I would need a reproduction case I haven't noticed anything

[vanarok]

Similarly, I noticed that sometimes hangs appear during autocomplete module import.

[the-mikedavis]

Actually I believe we do still block the UI on resolving completion items:

helix/helix-term/src/ui/completion.rs

Lines 293 to 300 in cd02976

	// resolve item if not yet resolved
	if !item.resolved {
	if let Some(resolved) =
	Self::resolve_completion_item(language_server, item.item.clone())
	{
	item.item = resolved;
	}
	};

when accepting a completion item that isn't resolved yet.

We also resolve them asynchronously when you've hovered over a completion item for a while. (This was done after the idle timeout since #4781 and now after 150ms since #9668.) So I suspect this is reproducible when you're fast enough to accept the completion item before it is resolved automatically

[pascalkuthe]

Hmm I am not sure that matters. The item is only marked as resolved after the server fulfills the request. So if the server takes 20 seconds to resolve it doesn't matter if you confirm the item within the timeout we would always block.

I read the issue as being about selecting completions ( as in scroll up/down) not actually confirming them.

For confirming a selection case blocking on resolving them makes sense. We can't apply the completion until the item is resolved altough we could use a more aggressive timeout.

[dirksierd]

For what it's worth, I've been seeing this too (with vuels/volar), for as long as I'm using Helix, I believe.
It seems to only happen once, after the timeout-block has happened it never happens again as long as I keep helix open.

Attached you'll find the logs from a verbose-session.
I've disabled my languages.toml-custom config.
I've made a new Vite Vue-project, without any additional dependencies.

Logs

hx.log

Platform

macOS 14.4 (23E214)

Terminal Emulator

Alacritty 0.13.1 (fe2a3c5)

Helix Version

23.10 (f5d95de)