Clojure crashing the editor

[HiiGHoVuTi]

Summary

The bug is really simple, the helix-lsp-client seems to crash when editing clojure code.
At first the editing works and at some point it crashes and from then on, it is impossible to re-open the file without the editor crashing.

Reproduction Steps

I'm in a default lein project.

I tried this:

1. hx src/project/core.clj
2. go around changing some code

I expected this to happen:

being able to use helix to edit clojure files

Instead, this happened:

after some time editing the file, the editor crashes. When trying to re-open the file, it crashes immediately.

Helix log

~/.cache/helix/helix.log

Caused by:
    channel closed)
2022-08-11T10:46:32.297 helix_term::application [ERROR] Language Server: Method not found client/registerCapability
2022-08-11T10:53:21.546 helix_lsp::client [WARN] language server failed to terminate gracefully - failed to parse: invalid type: map, expected unit
2022-08-11T10:54:14.728 helix_lsp::transport [ERROR] err: <- Other(failed to send a message to server

Caused by:
    channel closed)
2022-08-11T10:55:26.963 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-08-11T10:55:26.963 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-08-11T10:56:30.952 helix_lsp::transport [ERROR] err: <- Other(failed to send a message to server

Caused by:
    channel closed)
2022-08-11T10:57:14.206 helix_lsp::transport [ERROR] err: <- Other(failed to send a message to server

Caused by:
    channel closed)

or sometimes

Caused by:
    channel closed)
2022-08-11T11:11:55.481 helix_view::editor [ERROR] Failed to initialize the LSP for `source.clojure` { cannot find binary path }
2022-08-11T11:12:00.294 helix_view::editor [ERROR] Failed to initialize the LSP for `source.clojure` { cannot find binary path }

(clojure-lsp is in my path and it's found sometimes)

on top of that, the instantaneous crash when I open the file doesn't produce any logs !

Rust stack trace

Here are the rust logs, since they were provided too:

thread 'main' panicked at 'called `Option::unwrap()` on a `None` value', /build/81fl2hx743wzi1fr8zmak81ggyahvz9m-source/helix-term/src/application.rs:513:81
stack backtrace:
   0:     0x55eff7d2d494 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h9c2a9d2774d81873
   1:     0x55eff756b76c - core::fmt::write::hba4337c43d992f49
   2:     0x55eff7d26e75 - std::io::Write::write_fmt::heb73de6e02cfabed
   3:     0x55eff7d2f33e - std::panicking::default_hook::{{closure}}::hc9a76eed0b18f82b
   4:     0x55eff7d2f06d - std::panicking::default_hook::h2e88d02087fae196
   5:     0x55eff7bb8c6c - helix_term::application::Application::run::{{closure}}::{{closure}}::h2a171355ca53c72c
   6:     0x55eff7d2f9cb - std::panicking::rust_panic_with_hook::habfdcc2e90f9fd4c
   7:     0x55eff7d2f7cc - std::panicking::begin_panic_handler::{{closure}}::he054b2a83a51d2cd
   8:     0x55eff7d2d9c4 - std::sys_common::backtrace::__rust_end_short_backtrace::ha48b94ab49b30915
   9:     0x55eff7d2f55d - rust_begin_unwind
  10:     0x55eff74ead53 - core::panicking::panic_fmt::h366d3a309ae17c94
  11:     0x55eff74eac1d - core::panicking::panic::h8705e81f284be8a5
  12:     0x55eff7be8085 - core::ops::function::impls::<impl core::ops::function::FnMut<A> for &mut F>::call_mut::h8c3d620290629383
  13:     0x55eff7ba79ae - <alloc::vec::Vec<T> as alloc::vec::spec_from_iter::SpecFromIter<T,I>>::from_iter::ha0789922cc9bb92c
  14:     0x55eff7bb6eb6 - helix_term::application::Application::event_loop_until_idle::{{closure}}::h8be88e44471bed39
  15:     0x55eff7bd30bb - <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll::h00641bb03ff36fdd
  16:     0x55eff7bab4a2 - std::thread::local::LocalKey<T>::with::h4a2650524fd0402e
  17:     0x55eff7b93688 - tokio::park::thread::CachedParkThread::block_on::h23825ea45ad693b3
  18:     0x55eff7bf48b8 - tokio::runtime::thread_pool::ThreadPool::block_on::h7d48bcf67d5258ff
  19:     0x55eff7bcfd83 - tokio::runtime::Runtime::block_on::hab8dd3ba388c1c22
  20:     0x55eff7b8b936 - hx::main::h8012874220ecbbec
  21:     0x55eff7b8ba63 - std::sys_common::backtrace::__rust_begin_short_backtrace::h8b4ea23ef8b6946e
  22:     0x55eff7bab19d - std::rt::lang_start::{{closure}}::hc01c98d73647ef30
  23:     0x55eff7d2170b - std::rt::lang_start_internal::h9c06694362b5b80c
  24:     0x55eff7b8ba42 - main
  25:     0x7fd6da83b237 - __libc_start_call_main
  26:     0x7fd6da83b2f5 - __libc_start_main_impl
  27:     0x55eff7520ef1 - _start
  28:                0x0 - <unknown>

Platform

Linux (NixOS)

Terminal Emulator

wezterm

Helix Version

helix 22.05 (d192d59)

[the-mikedavis]

I tried poking around in a clojure project for a while but I couldn't reproduce this with the clojure-lsp from nixpkgs unstable:

clojure-lsp 2022.07.24-18.25.43
clj-kondo 2022.06.23-SNAPSHOT

The panic comes from the handling of LSP PublishDiagnostics here:

helix/helix-term/src/application.rs

Line 513 in 80dde57

let language_server = doc.language_server().unwrap();

which looks like it can be None if the language server's capabilities are not set up yet, although I'm not sure what series of events could lead to that.

Can you reproduce this running in verbose mode (hx -v) and post the log? Verbose mode will spit out the messages between the language server and helix.

[HiiGHoVuTi]

and here are some logs:

2022-08-11T16:26:43.597 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Analyzing external classpath","percentage":43}}}
2022-08-11T16:26:43.600 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Analyzing external classpath","percentage":43}}}
2022-08-11T16:26:43.601 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Analyzing external classpath","percentage":44}}}
2022-08-11T16:26:43.798 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Resolving config paths","percentage":45}}}
2022-08-11T16:26:43.798 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Analyzing project files","percentage":50}}}
2022-08-11T16:26:43.799 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Analyzing project files","percentage":74}}}
2022-08-11T16:26:43.800 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"report","message":"Analyzing project files","percentage":99}}}
2022-08-11T16:26:43.805 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"$/progress","params":{"token":"clojure-lsp","value":{"kind":"end","message":"Project analyzed"}}}
2022-08-11T16:26:43.806 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/maxime/tmp/t/test/t/core_test.clj","diagnostics":[{"range":{"start":{"line":1,"character":33},"end":{"line":1,"character":37}},"severity":2,"code":"refer-all","source":"clj-kondo","message":"use alias or :refer [deftest is testing]","tags":[]},{"range":{"start":{"line":2,"character":27},"end":{"line":2,"character":31}},"severity":2,"code":"refer-all","source":"clj-kondo","message":"use alias or :refer","tags":[]}]}}
2022-08-11T16:26:43.806 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":0,"result":{"capabilities":{"textDocumentSync":{"openClose":true,"change":1,"save":{"includeText":true}},"hoverProvider":true,"completionProvider":{"resolveProvider":true,"triggerCharacters":[":","/"]},"signatureHelpProvider":{"triggerCharacters":[]},"definitionProvider":true,"implementationProvider":true,"referencesProvider":true,"documentHighlightProvider":true,"documentSymbolProvider":true,"workspaceSymbolProvider":true,"codeActionProvider":{"codeActionKinds":["quickfix","refactor","refactor.extract","refactor.inline","refactor.rewrite","source","source.organizeImports"]},"codeLensProvider":{"resolveProvider":true},"documentFormattingProvider":true,"documentRangeFormattingProvider":true,"renameProvider":{"prepareProvider":true},"declarationProvider":true,"executeCommandProvider":{"commands":["add-import-to-namespace","add-missing-import","add-missing-libspec","add-require-suggestion","change-coll","clean-ns","create-function","create-test","cycle-coll","cycle-privacy","demote-fn","destructure-keys","drag-backward","drag-forward","expand-let","extract-function","extract-to-def","inline-symbol","introduce-let","move-coll-entry-down","move-coll-entry-up","move-form","move-to-let","promote-fn","resolve-macro-as","sort-map","suppress-diagnostic","thread-first","thread-first-all","thread-last","thread-last-all","unwind-all","unwind-thread"]},"workspace":{"fileOperations":{"willRename":{"filters":[{"pattern":{"glob":"**/*.{clj,cljs,cljc,cljd,edn,bb,clj_kondo}","matches":"file"},"scheme":"file"}]}}},"callHierarchyProvider":true,"linkedEditingRangeProvider":true,"semanticTokensProvider":{"legend":{"tokenTypes":["namespace","type","function","macro","keyword","class","variable","method","event"],"tokenModifiers":["definition","defaultLibrary","implementation"]},"range":true,"full":true},"experimental":{"testTree":true,"cursorInfo":true,"serverInfo":true,"clojuredocs":true}}}}
2022-08-11T16:26:43.806 helix_lsp::transport [INFO] <- {"capabilities":{"callHierarchyProvider":true,"codeActionProvider":{"codeActionKinds":["quickfix","refactor","refactor.extract","refactor.inline","refactor.rewrite","source","source.organizeImports"]},"codeLensProvider":{"resolveProvider":true},"completionProvider":{"resolveProvider":true,"triggerCharacters":[":","/"]},"declarationProvider":true,"definitionProvider":true,"documentFormattingProvider":true,"documentHighlightProvider":true,"documentRangeFormattingProvider":true,"documentSymbolProvider":true,"executeCommandProvider":{"commands":["add-import-to-namespace","add-missing-import","add-missing-libspec","add-require-suggestion","change-coll","clean-ns","create-function","create-test","cycle-coll","cycle-privacy","demote-fn","destructure-keys","drag-backward","drag-forward","expand-let","extract-function","extract-to-def","inline-symbol","introduce-let","move-coll-entry-down","move-coll-entry-up","move-form","move-to-let","promote-fn","resolve-macro-as","sort-map","suppress-diagnostic","thread-first","thread-first-all","thread-last","thread-last-all","unwind-all","unwind-thread"]},"experimental":{"clojuredocs":true,"cursorInfo":true,"serverInfo":true,"testTree":true},"hoverProvider":true,"implementationProvider":true,"linkedEditingRangeProvider":true,"referencesProvider":true,"renameProvider":{"prepareProvider":true},"semanticTokensProvider":{"full":true,"legend":{"tokenModifiers":["definition","defaultLibrary","implementation"],"tokenTypes":["namespace","type","function","macro","keyword","class","variable","method","event"]},"range":true},"signatureHelpProvider":{"triggerCharacters":[]},"textDocumentSync":{"change":1,"openClose":true,"save":{"includeText":true}},"workspace":{"fileOperations":{"willRename":{"filters":[{"pattern":{"glob":"**/*.{clj,cljs,cljc,cljd,edn,bb,clj_kondo}","matches":"file"},"scheme":"file"}]}}},"workspaceSymbolProvider":true}}
2022-08-11T16:26:43.806 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///home/maxime/tmp/t/src/t/core.clj","diagnostics":[{"range":{"start":{"line":2,"character":6},"end":{"line":2,"character":9}},"severity":3,"code":"clojure-lsp/unused-public-var","source":"clojure-lsp","message":"Unused public var \u0027t.core/foo\u0027","tags":[1]}]}}
2022-08-11T16:26:43.806 helix_lsp::transport [INFO] -> {"jsonrpc":"2.0","method":"initialized","params":{}}
2022-08-11T16:26:43.807 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":"1","method":"client/registerCapability","params":{"registrations":[{"id":"id","method":"workspace/didChangeWatchedFiles","registerOptions":{"watchers":[{"globPattern":"**/*.{clj,cljs,cljc,cljd,edn,bb,clj_kondo}"}]}}]}}

[HiiGHoVuTi]

retrying without -v on a new project gave me this interesting line:

2022-08-11T16:32:24.778 helix_term::application [ERROR] Timed out waiting for language servers to shutdown

which is the only line logged before crashing

[the-mikedavis]

Ah, these two lines are interesting:

2022-08-11T16:26:43.806 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics",...
2022-08-11T16:26:43.806 helix_lsp::transport [INFO] <- {"jsonrpc":"2.0","id":0,"result":{"capabilities":...

Looks like clojure-lsp is sending a textDocument/publishDiagnostics before the initializeResult which is invalid according to the LSP spec. If you have a reliable reproduction case you can share (they would probably want an example project that exhibits the behavior), it would be good to report this upstream to clojure-lsp. I haven't been able to reproduce oddly.

That being said, we've been trying to be more defensive about spec violations: we should discard messages and not panic when the server breaks spec. I've opened a PR to log and discard the textDocument/publishDiagnostic if it's received before the language server is initialized: #3403. Could you give that a try and see if that prevents the panic?

[HiiGHoVuTi]

Today I cannot reproduce this bug, even though I changed nothing in my setup (unless there was a sneaky update?).
Your diagnostic makes sense with what I was experiencing, so I hope it won't happen to other people (or future me).
If I come across it again I'll upgrade and file an issue to clojure-lsp.