Fails to recover from lsp server dying; only "broken pipe" errors

[jwatzman]

It looks like if the LSP that the plugin has connected to dies for any reason, then LanguageClient-neovim does not detect this error case, and just spews "broken pipe" errors until the language support is restarted. I would instead expect the plugin to detect this error case and automatically connect to a new LSP.

I was able to reproduce this across a couple of different environments/languages. I first noticed it with an in-house language/LSP at work (which for reasons I won't go into loves to restart itself). Sadly this one is not public right now so I can't link that one, but I was able to reproduce exactly the same behaviour with rls using kilall rls to simulate a crash.

I've gone ahead and filled out the below for the nvim/rls case, though this is quite easy to reproduce.

• neovim/vim version: neovim 0.2.0
• Plugin version (git SHA): 63af88b
• Minimal vimrc:

call plug#begin()

Plug 'autozimu/LanguageClient-neovim', {
    \ 'branch': 'next',
    \ 'do': 'bash install.sh',
    \ }

call plug#end()

augroup filetype_rust
    autocmd!
    autocmd BufReadPost *.rs setlocal filetype=rust
augroup END

let g:LanguageClient_serverCommands = {
    \ 'rust': ['rustup', 'run', 'stable', 'rls'],
    \ }
let g:LanguageClient_loggingLevel = 'DEBUG'
nnoremap <silent> K :call LanguageClient_textDocument_hover()<CR>

• Language server name/link and version: rls-preview 0.124.0-stable (299a6a9 2017-12-25)
• Reproduction steps (from clean state)
  1. Edit any rust file, e.g., nvim main.rs
  2. Press K (hover), no error.
  3. In another terminal, killall rls to simulate an LSP crash.
  4. Press K again (or any other LSP action), get only Broken pipe (os error 32) which the plugin fails to recover from.
• /tmp/LanguageServer.log: empty
• /tmp/LanguageClient.log: quite long, here's the relevant bit at the end (can include the whole thing if you want, though again this is quite easy to reproduce):

2018-03-03T19:03:56.569898910+00:00 INFO languageclient::vim - <= {"id": 1, "jsonrpc": "2.0", "method": "textDocument/hover", "params": {"character": 0, "handle": true, "languageId": "rust", "line": 0, "buftype": "", "filename": "/home/josh/test/src/main.rs"}}
2018-03-03T19:03:56.570657774+00:00 INFO languageclient::languageclient - Begin textDocument/hover
2018-03-03T19:03:56.570709700+00:00 INFO languageclient::languageclient - gather_args: [LanguageId, Filename, Line, Character, Handle] = [String("rust"), String("/home/josh/test/src/main.rs"), Number(0), Number(0), Bool(true)]
2018-03-03T19:03:56.571082889+00:00 DEBUG languageclient::vim - state.id: 11 ==> 12
2018-03-03T19:03:56.571376175+00:00 INFO languageclient::vim - => {"jsonrpc":"2.0","method":"textDocument/hover","params":{"position":{"character":0,"line":0},"textDocument":{"uri":"file:///home/josh/test/src/main.rs"}},"id":12}
2018-03-03T19:03:56.572328841+00:00 INFO languageclient::vim - <= {"jsonrpc":"2.0","id":12,"result":{"contents":[],"range":null}}
2018-03-03T19:03:56.572773794+00:00 INFO languageclient::vim - => {"jsonrpc":"2.0","method":"execute","params":["echo ''"]}
2018-03-03T19:03:56.572811059+00:00 INFO languageclient::languageclient - End textDocument/hover
2018-03-03T19:03:56.572831314+00:00 INFO languageclient::vim - => {"jsonrpc":"2.0","result":{"contents":[],"range":null},"id":1}
2018-03-03T19:03:59.557818538+00:00 ERROR languageclient::languageclient - RPC-rust thread error: failed to fill whole buffer
2018-03-03T19:04:00.527327477+00:00 INFO languageclient::vim - <= {"id": 2, "jsonrpc": "2.0", "method": "textDocument/hover", "params": {"character": 0, "handle": true, "languageId": "rust", "line": 0, "buftype": "", "filename": "/home/josh/test/src/main.rs"}}
2018-03-03T19:04:00.528061035+00:00 INFO languageclient::languageclient - Begin textDocument/hover
2018-03-03T19:04:00.528092130+00:00 INFO languageclient::languageclient - gather_args: [LanguageId, Filename, Line, Character, Handle] = [String("rust"), String("/home/josh/test/src/main.rs"), Number(0), Number(0), Bool(true)]
2018-03-03T19:04:00.528332051+00:00 DEBUG languageclient::vim - state.id: 12 ==> 13
2018-03-03T19:04:00.528597770+00:00 INFO languageclient::vim - => {"jsonrpc":"2.0","method":"textDocument/hover","params":{"position":{"character":0,"line":0},"textDocument":{"uri":"file:///home/josh/test/src/main.rs"}},"id":13}
2018-03-03T19:04:00.528786347+00:00 ERROR languageclient::vim - Error handling message. Message: {"id": 2, "jsonrpc": "2.0", "method": "textDocument/hover", "params": {"character": 0, "handle": true, "languageId": "rust", "line": 0, "buftype": "", "filename": "/home/josh/test/src/main.rs"}}. Error: Err(Error { repr: Os { code: 32, message: "Broken pipe" } })
2018-03-03T19:04:00.528811260+00:00 INFO languageclient::vim - => {"jsonrpc":"2.0","error":{"code":-32603,"message":"Broken pipe (os error 32)"},"id":2}

[jwatzman]

It looks like this prevents even LanguageClientStop from working, so I can't get out of this state without restarting vim/nvim entirely.

[jwatzman]

Thanks for the fix, seems to have made things a lot better.

[Marwes]

I think I am seeing the same issue

2018-03-22T11:06:44.593199+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:01.095820+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:03.230535+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:07.836210+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:07.840327+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:07.840764+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:09.909783+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:14.703621+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:16.504673+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:20.605832+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:20.609764+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:09:20.745597+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:10:55.969573+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:10:57.294430+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:01.947206+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:07.500178+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:07.504567+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:07.658099+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:09.009468+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:09.010320+01:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-22T11:11:48.337495+01:00 ERROR languageclient::languageclient - RPC-rust thread error: failed to fill whole buffer
2018-03-22T11:11:48.347531+01:00 ERROR languageclient::vim - Error handling message. Message: {"method": "languageClient/handleTextChanged", "jsonrpc": "2.0", "params": {"languageId": "rust", "buftype": "", "text": [], "filename": "/<SNIP>/mod.rs"}}. Error: Error { repr: Os { code: 32, message: "Broken pipe" } }

[Marwes]

Might be due to rust-lang/rls#783 (though I have seen these errors in LanguageClient.log without seeing the error in rust-lang/rls#783 LanguageServer.log)

[Marwes]

I think I have a backtrace for this issue.

LanguageClient.log

2018-03-27T10:55:36.115092+02:00 ERROR languageclient::vim - Error handling message. Message: {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"diagnostics":[],"uri":"file:///Users/<PATH>/mod.rs"}}. Error: ErrorMessage { msg: "TextDocumentItem not found! filename: /Users/<PATH>/mod.rs" }

stack backtrace:
   0:        0x100f94f3e - backtrace::backtrace::trace::h90f6cf3afa8029d8
   1:        0x100f93ffc - backtrace::capture::Backtrace::new_unresolved::h49c8696e98b2d6ff
   2:        0x100f9314c - failure::backtrace::internal::InternalBacktrace::new::h396ee55657947c7d
   3:        0x100f93304 - failure::backtrace::Backtrace::new::ha79fb670ebd3cfd7
   4:        0x100e7f24d - languageclient::languageclient::ILanguageClient::display_diagnostics::h274e38dc36dad68b
   5:        0x100e6ea3d - _$LT$alloc..arc..Arc$LT$std..sync..mutex..Mutex$LT$languageclient..types..State$GT$$GT$$u20$as$u20$languageclient..rpchandler..IRpcHandler$GT$::handle_notification::h2d37fd26d79ed9dd
   6:        0x100e1c017 - languageclient::vim::IVim::handle_message::hcf868b13f8a608e5
   7:        0x100e06159 - std::sys_common::backtrace::__rust_begin_short_backtrace::h6568d4079c9e5683
   8:        0x100e06427 - std::panicking::try::do_call::h26adcf9954a38717 (.llvm.4BB58E11)
   9:        0x10106c66e - __rust_maybe_catch_panic
  10:        0x100ee204f - _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h71b5467ed416ea98
  11:        0x101057317 - std::sys_common::thread::start_thread::h955915a516ba675d
  12:        0x10105a8c8 - std::sys::unix::thread::Thread::new::thread_start::h9cf88adb0b0cce85
  13:     0x7fff6a0af6c0 - _pthread_body
  14:     0x7fff6a0af56c - _pthread_start
2018-03-27T10:55:36.427607+02:00 WARN languageclient::rpchandler - Unknown notification: "window/progress"
2018-03-27T10:55:41.065930+02:00 WARN languageclient::languageclient - Not opened yet. Switching to didOpen.
2018-03-27T10:55:41.369850+02:00 ERROR languageclient::languageclient - RPC-rust thread error: failed to fill whole buffer
2018-03-27T10:55:41.485852+02:00 ERROR languageclient::vim - Error handling message. Message: {"method": "languageClient/handleTextChanged", "jsonrpc": "2.0", "params": {"languageId": "rust", "buftype": "", "text": ["CODE"], "filename": "/Users/<PATH>/mod.rs"}}. Error: Error { repr: Os { code: 32, message: "Broken pipe" } }

stack backtrace:
   0:        0x100f94f3e - backtrace::backtrace::trace::h90f6cf3afa8029d8
   1:        0x100f93ffc - backtrace::capture::Backtrace::new_unresolved::h49c8696e98b2d6ff
   2:        0x100f9314c - failure::backtrace::internal::InternalBacktrace::new::h396ee55657947c7d
   3:        0x100f93304 - failure::backtrace::Backtrace::new::ha79fb670ebd3cfd7
   4:        0x100e1f608 - languageclient::vim::IVim::write::hb8a85e9b201eed16
   5:        0x100eacef4 - languageclient::languageclient::ILanguageClient::textDocument_didChange::h39c63cf0635c6970
   6:        0x100e63c6e - _$LT$alloc..arc..Arc$LT$std..sync..mutex..Mutex$LT$languageclient..types..State$GT$$GT$$u20$as$u20$languageclient..rpchandler..IRpcHandler$GT$::handle_notification::h2d37fd26d79ed9dd
   7:        0x100e1c017 - languageclient::vim::IVim::handle_message::hcf868b13f8a608e5
   8:        0x100e05ea9 - std::sys_common::backtrace::__rust_begin_short_backtrace::h5115e0d66f4d9904
   9:        0x100e06477 - std::panicking::try::do_call::h6d872903689e1d5f (.llvm.4BB58E11)
  10:        0x10106c66e - __rust_maybe_catch_panic
  11:        0x100ee1e4f - _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h0061a0c1a15b99e3
  12:        0x101057317 - std::sys_common::thread::start_thread::h955915a516ba675d
  13:        0x10105a8c8 - std::sys::unix::thread::Thread::new::thread_start::h9cf88adb0b0cce85
  14:     0x7fff6a0af6c0 - _pthread_body
  15:     0x7fff6a0af56c - _pthread_start

The handleTextChanged errors keep repeating at this point.

LanguageServer.log

ERROR 2018-03-27T08:42:56Z: rls::server: Can't read message
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }', libcore/result.rs:945:5
note: Run with `RUST_BACKTRACE=1` for a backtrace.
error: expected one of `;` or `as`, found `use`
 --> bogofile:3:1
  |
3 | use std::sync::Arc;
  | ^^^

thread 'main' panicked at 'Out of order or duplicate change', tools/rls/src/actions/mod.rs:272:13
stack backtrace:
   0: std::sys::unix::backtrace::tracing::imp::unwind_backtrace
   1: std::sys_common::backtrace::print
   2: std::panicking::default_hook::{{closure}}
   3: std::panicking::default_hook
   4: core::ops::function::Fn::call
   5: std::panicking::rust_panic_with_hook
   6: std::panicking::begin_panic
   7: rls::actions::InitActionContext::check_change_version
   8: rls::actions::notifications::<impl rls::server::message::BlockingNotificationAction for languageserver_types::notification::DidChangeTextDocument>::handle
   9: rls::server::run_server
  10: rls::main
  11: std::rt::lang_start::{{closure}}
  12: std::panicking::try::do_call
  13: __rust_maybe_catch_panic
  14: std::rt::lang_start_internal
  15: main

[TysonAndre]

I would instead expect the plugin to detect this error case and automatically connect to a new LSP.

What's the current status of this ticket? My best guess is that automatic reconnection is still a feature request?

• E.g. I'd want to be able to automatically restart the language server process, unless it crashed X times in the last Y minutes. (e.g. "crash" meaning the language server process died)

I read the latest LanguageClient.txt help text and didn't see anything about automatic restarts. (I'm asking in case I missed a setting)

The most recent commit (f494...) looks like it just fixes a bug in stopping the language server

---

Unrelated: When a language server dies, is there a way to automatically clear all of the emitted issues (Both in signcolumn and in quickfix list). They stay around for me, even when the cause of the issue is fixed.

• E.g. even as a workaround immediately after the LanguageClientStarted event

Never mind, I saw call setqflist([]) can do that for the QuickFix list and there's an issue already filed.
I'm using the latest LanguageClient-neovim and binary; The sign column errors are cleared properly for me if I manually kill the language server process with pkill

" Hackish fix to hide QuickFix errors immediately after language server dies
" (Limitation: This will also hide quickFix errors from other sources)
augroup LanguageClient_config
  autocmd!
  " other commands can go here
  " Discard all errors in the QuickFix window if the language server stops or crashes
  autocmd User LanguageClientStopped call setqflist([])
augroup end

[lorenzo]

I would like to help implement this. @autozimu can you maybe guide me to the places I should modify to have the client restart the server automatically?

[autozimu]

You can check

LanguageClient-neovim/src/languageclient.rs

Lines 2871 to 2890 in f736b52

	pub fn languageClient_serverExited(&mut self, params: &Value) -> Result<()> {
	let (languageId, message): (String, String) = self.gather_args(
	[VimVar::LanguageId.to_key().as_str(), "message"].as_ref(),
	params,
	)?;
	if self.writers.contains_key(&languageId) {
	if let Err(err) = self.cleanup(&languageId) {
	error!("Error in cleanup: {:?}", err);
	}
	if let Err(err) = self.echoerr(format!(
	"Language server {} exited unexpectedly: {}",
	languageId, message
	)) {
	error!("Error in echoerr: {:?}", err);
	}
	}
	Ok(())
	}

The tricky parts are two fold

1. detect current context is server exited unexpectedly, not user requested.
2. gather correct parameters to restart server.

[lorenzo]

Thanks! I'll take a look at it during the week

[martskins]

Closing via #1113