helix: Hang when write-quit

This issue covers a few cases now:

• #2267 fixed the hang for write-quitting large files (not related to LSP)
• #4797 fixed the hang for language servers that crash
• #4852 fixed the case for efm-langserver (exiting but not responding to shutdown)
• taplo is an upstream issue

The remaining case is the hang from trying to auto-format while the server is initializing. For that we have https://github.com/helix-editor/helix/issues/2059; I’ll close in favor of that issue.

For taplo this looks like an upstream issue. Taplo is currently discarding LSP shutdown messages. We block awaiting the shutdown response before sending the exit notification but taplo doesn’t currently respond to the shutdown request, so we time out. https://github.com/tamasfe/taplo/pull/354

You can see in a verbose log that we wait for a while after the request to shutdown:

2022-11-20T12:32:10.728 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"initialize","params":{"capabilities":{"textDocument":{"codeAction":{"codeActionLiteralSupport":{"codeActionKind":{"valueSet":["","quickfix","refactor","refactor.extract","refactor.inline","refactor.rewrite","source","source.organizeImports"]}}},"completion":{"completionItem":{"insertReplaceSupport":true,"resolveSupport":{"properties":["documentation","detail","additionalTextEdits"]},"snippetSupport":false},"completionItemKind":{}},"hover":{"contentFormat":["markdown"]},"publishDiagnostics":{},"rename":{"dynamicRegistration":false,"honorsChangeAnnotations":false,"prepareSupport":false},"signatureHelp":{"signatureInformation":{"activeParameterSupport":true,"documentationFormat":["markdown"],"parameterInformation":{"labelOffsetSupport":true}}}},"window":{"workDoneProgress":true},"workspace":{"applyEdit":true,"configuration":true,"didChangeConfiguration":{"dynamicRegistration":false},"executeCommand":{"dynamicRegistration":false},"symbol":{"dynamicRegistration":false},"workspaceFolders":true}},"processId":166572,"rootPath":"/home/michael/src/helix/hx","rootUri":"file:///home/michael/src/helix/hx","workspaceFolders":[{"name":"hx","uri":"file:///home/michael/src/helix/hx"}]},"id":0}
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"initialize\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/foldingRange\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/documentSymbol\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/formatting\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/completion\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/hover\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/documentLink\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/semanticTokens/full\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/prepareRename\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/rename\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"initialized\"\n"
2022-11-20T12:32:10.743 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didOpen\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didChange\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didSave\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didClose\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"workspace/didChangeConfiguration\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"workspace/didChangeWorkspaceFolders\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/convertToJson\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/convertToToml\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/listSchemas\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/associatedSchema\"\n"
2022-11-20T12:32:10.744 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"taplo/associateSchema\"\n"
2022-11-20T12:32:10.746 helix_lsp::transport [ERROR] err <- " INFO taplo: LSP server listening transport=\"stdio\"\n"
2022-11-20T12:32:11.734 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":0,"result":{"capabilities":{"textDocumentSync":1,"hoverProvider":true,"completionProvider":{"resolveProvider":false,"triggerCharacters":[".","=","[","{",",","\""]},"documentSymbolProvider":true,"documentFormattingProvider":true,"renameProvider":{"prepareProvider":true},"documentLinkProvider":{},"foldingRangeProvider":true,"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":true}},"semanticTokensProvider":{"workDoneProgress":false,"legend":{"tokenTypes":["tomlArrayKey","tomlTableKey"],"tokenModifiers":["readonly"]},"range":false,"full":true}},"serverInfo":{"name":"Taplo","version":"0.6.0"}}}
2022-11-20T12:32:11.734 helix_lsp::transport [INFO] <- {"capabilities":{"completionProvider":{"resolveProvider":false,"triggerCharacters":[".","=","[","{",",","\""]},"documentFormattingProvider":true,"documentLinkProvider":{},"documentSymbolProvider":true,"foldingRangeProvider":true,"hoverProvider":true,"renameProvider":{"prepareProvider":true},"semanticTokensProvider":{"full":true,"legend":{"tokenModifiers":["readonly"],"tokenTypes":["tomlArrayKey","tomlTableKey"]},"range":false,"workDoneProgress":false},"textDocumentSync":1,"workspace":{"workspaceFolders":{"changeNotifications":true,"supported":true}}},"serverInfo":{"name":"Taplo","version":"0.6.0"}}
2022-11-20T12:32:11.735 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"initialized","params":{}}
2022-11-20T12:32:11.735 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"textDocument/didOpen","params":{"textDocument":{"languageId":"toml","text":"[workspace]\nmembers = [\n  \"helix-core\",\n  \"helix-view\",\n  \"helix-term\",\n  \"helix-tui\",\n  \"helix-lsp\",\n  \"helix-dap\",\n  \"helix-loader\",\n  \"xtask\",\n]\n\ndefault-members = [\n  \"helix-term\"\n]\n\n[profile.release]\nlto = \"thin\"\n# debug = true\n\n[profile.opt]\ninherits = \"release\"\nlto = \"fat\"\ncodegen-units = 1\n# strip = \"debuginfo\" # TODO: or strip = true\nopt-level = 3\n","uri":"file:///home/michael/src/helix/hx/Cargo.toml","version":0}}}
2022-11-20T12:32:11.735 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"workspace/configuration","id":0,"params":{"items":[{"section":"evenBetterToml"},{"scopeUri":"file:///home/michael/src/helix/hx","section":"evenBetterToml"}]}}
2022-11-20T12:32:11.743 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null,null],"id":0}
2022-11-20T12:32:11.746 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/michael/src/helix/hx/Cargo.toml","diagnostics":[]}}
2022-11-20T12:32:11.746 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/michael/src/helix/hx/Cargo.toml","diagnostics":[]}}
2022-11-20T12:32:12.317 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/michael/src/helix/hx/Cargo.toml","diagnostics":[]}}
2022-11-20T12:32:14.617 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"shutdown","params":null,"id":1}
2022-11-20T12:32:17.617 helix_term::application [ERROR] Timed out waiting for language servers to shutdown

Running with taplo built from that PR, :quit exits in a normal amount of time:

2022-11-20T12:35:20.569 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"initialize","params":{"capabilities":{"textDocument":{"codeAction":{"codeActionLiteralSupport":{"codeActionKind":{"valueSet":["","quickfix","refactor","refactor.extract","refactor.inline","refactor.rewrite","source","source.organizeImports"]}}},"completion":{"completionItem":{"insertReplaceSupport":true,"resolveSupport":{"properties":["documentation","detail","additionalTextEdits"]},"snippetSupport":false},"completionItemKind":{}},"hover":{"contentFormat":["markdown"]},"publishDiagnostics":{},"rename":{"dynamicRegistration":false,"honorsChangeAnnotations":false,"prepareSupport":false},"signatureHelp":{"signatureInformation":{"activeParameterSupport":true,"documentationFormat":["markdown"],"parameterInformation":{"labelOffsetSupport":true}}}},"window":{"workDoneProgress":true},"workspace":{"applyEdit":true,"configuration":true,"didChangeConfiguration":{"dynamicRegistration":false},"executeCommand":{"dynamicRegistration":false},"symbol":{"dynamicRegistration":false},"workspaceFolders":true}},"processId":167615,"rootPath":"/home/michael/src/helix/hx","rootUri":"file:///home/michael/src/helix/hx","workspaceFolders":[{"name":"hx","uri":"file:///home/michael/src/helix/hx"}]},"id":0}
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"initialize\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/foldingRange\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/documentSymbol\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/formatting\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/completion\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/hover\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/documentLink\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/semanticTokens/full\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/prepareRename\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"textDocument/rename\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"initialized\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didOpen\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didChange\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didSave\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"textDocument/didClose\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"workspace/didChangeConfiguration\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"workspace/didChangeWorkspaceFolders\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/convertToJson\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/convertToToml\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/listSchemas\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered request handler method=\"taplo/associatedSchema\"\n"
2022-11-20T12:35:20.585 helix_lsp::transport [ERROR] err <- " INFO taplo: registered notification handler method=\"taplo/associateSchema\"\n"
2022-11-20T12:35:20.587 helix_lsp::transport [ERROR] err <- " INFO taplo: LSP server listening transport=\"stdio\"\n"
2022-11-20T12:35:21.394 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":0,"result":{"capabilities":{"textDocumentSync":1,"hoverProvider":true,"completionProvider":{"resolveProvider":false,"triggerCharacters":[".","=","[","{",",","\""]},"documentSymbolProvider":true,"documentFormattingProvider":true,"renameProvider":{"prepareProvider":true},"documentLinkProvider":{},"foldingRangeProvider":true,"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":true}},"semanticTokensProvider":{"workDoneProgress":false,"legend":{"tokenTypes":["tomlArrayKey","tomlTableKey"],"tokenModifiers":["readonly"]},"range":false,"full":true}},"serverInfo":{"name":"Taplo","version":"0.6.0"}}}
2022-11-20T12:35:21.395 helix_lsp::transport [INFO] <- {"capabilities":{"completionProvider":{"resolveProvider":false,"triggerCharacters":[".","=","[","{",",","\""]},"documentFormattingProvider":true,"documentLinkProvider":{},"documentSymbolProvider":true,"foldingRangeProvider":true,"hoverProvider":true,"renameProvider":{"prepareProvider":true},"semanticTokensProvider":{"full":true,"legend":{"tokenModifiers":["readonly"],"tokenTypes":["tomlArrayKey","tomlTableKey"]},"range":false,"workDoneProgress":false},"textDocumentSync":1,"workspace":{"workspaceFolders":{"changeNotifications":true,"supported":true}}},"serverInfo":{"name":"Taplo","version":"0.6.0"}}
2022-11-20T12:35:21.395 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"initialized","params":{}}
2022-11-20T12:35:21.395 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"textDocument/didOpen","params":{"textDocument":{"languageId":"toml","text":"[workspace]\nmembers = [\n  \"helix-core\",\n  \"helix-view\",\n  \"helix-term\",\n  \"helix-tui\",\n  \"helix-lsp\",\n  \"helix-dap\",\n  \"helix-loader\",\n  \"xtask\",\n]\n\ndefault-members = [\n  \"helix-term\"\n]\n\n[profile.release]\nlto = \"thin\"\n# debug = true\n\n[profile.opt]\ninherits = \"release\"\nlto = \"fat\"\ncodegen-units = 1\n# strip = \"debuginfo\" # TODO: or strip = true\nopt-level = 3\n","uri":"file:///home/michael/src/helix/hx/Cargo.toml","version":0}}}
2022-11-20T12:35:21.396 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"workspace/configuration","id":0,"params":{"items":[{"section":"evenBetterToml"},{"scopeUri":"file:///home/michael/src/helix/hx","section":"evenBetterToml"}]}}
2022-11-20T12:35:21.404 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","result":[null,null],"id":0}
2022-11-20T12:35:21.407 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/michael/src/helix/hx/Cargo.toml","diagnostics":[]}}
2022-11-20T12:35:21.407 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/michael/src/helix/hx/Cargo.toml","diagnostics":[]}}
2022-11-20T12:35:21.975 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/michael/src/helix/hx/Cargo.toml","diagnostics":[]}}
2022-11-20T12:35:23.706 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"shutdown","params":null,"id":1}
2022-11-20T12:35:23.707 helix_lsp::transport [ERROR] err <- " INFO taplo: received shutdown request id=Number(1) method=shutdown\n"
2022-11-20T12:35:23.707 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":1,"result":null}
2022-11-20T12:35:23.707 helix_lsp::transport [INFO] <- null
2022-11-20T12:35:23.707 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"exit","params":null}

So I don’t think this is necessarily a bug per se, because it’s really in your interest to wait for your LS to shut down gracefully; otherwise, this could potentially lead to your project getting messed up. But there is more that could be done to help with the perception of what’s going on. Currently the whole UI just appears to hang because it’s happening after we’ve exited the main event loop that does all the rendering.

Perhaps we could use this issue to track improvements we could make. @archseer and I have discussed possibly moving the LSP shutdown procedure earlier, before it exits the rendering loop, and displaying a spinner and a message that the language servers are shutting down. We should also probably make the shutdown timeout configurable for those who would choose to prioritize shutting down more quickly over allowing the LS to shut down gracefully.

Ah that’s an interesting one: it looks like we send the shutdown request and the server just exits. The reply to shutdown seems to be discarded by the server since they consider the jsonrpc channel already closed. We can probably handle this by sending Errs for all pending_requests in the transport when we see that the stream is closed

If it’s a large file and the language doesn’t have a language server configured and you’re running on 22.08.1 instead of master, that is most likely https://github.com/helix-editor/helix/issues/3975 which was fixed in #2267

Also, what version are you running? The write path had big changes in #2267 after the latest release which may change the behavior (although I think that didn’t change the waiting for the LS part as dead10ck says).

In the future please use the bug report template.

That behavior should probably be fixed upstream in efm-langserver (the spec says you should exit when you get the exit notification) but in general Helix should be closing outstanding requests when the language server exits anyways: https://github.com/helix-editor/helix/pull/4852

@vanarok Can you retest on taplo/efm-lsp now that https://github.com/helix-editor/helix/pull/4797 was merged?

If it’s a large file and the language doesn’t have a language server configured and you’re running on 22.08.1 instead of master, that is most likely #3975 which was fixed in #2267

With :q without saving I still have this hang.

This is also a bit harder to do with rust-analyzer which immediately responds to the initialization request, but then will block on the formatting request until it’s able to fulfill it.

Not sure if this is related but the new rust-analyzer update mentions improvements for formatting requests during LSP startup.