kakoune-lsp icon indicating copy to clipboard operation
kakoune-lsp copied to clipboard

Published 20 hours ago • verified publisher icon kakoune-lsp

release build of kak-lsp hangs with unavailable language servers

Open Screwtapello opened this issue 6 years ago • 2 comments

Steps to reproduce

  1. Start kak-lsp manually:

     ./target/debug/kak-lsp -s hangtest

  2. Start Kakoune to edit a filetype whose language server is configured but not installed. I don't have the Python language server installed, so:

     kak -s hangtest foo.py

  3. kak-lsp complains that the server isn't available:

     Mar 27 12:24:23.849 INFO Starting main event loop, module: kak_lsp::session:31
 Mar 27 12:24:36.505 INFO Starting Language server `pyls `, module: kak_lsp::language_server_transport:19 thread '<unnamed>' panicked at 'Failed to start language server: Os { code: 2, kind: NotFound, message: "No such file or directory" }', src/libcore/result.rs:997:5
 note: Run with `RUST_BACKTRACE=1` environment variable to display a backtrace.

  4. Quit Kakoune

Expected results

  • kak-lsp exits, since it has nothing to do

Actual results

  • kak-lsp emits errors:

      Mar 27 12:24:40.388 INFO Shutting down language servers and exiting, module: kak_lsp::session:191
  Mar 27 12:24:40.388 ERRO Route { session: "hangtest", language: "python", root: "/home/st/foo.py" } controller panicked, module: kak_lsp::session:198
  Mar 27 12:24:40.388 INFO Exit python in project /home/st/foo.py, module: kak_lsp::session:200

  • kak-lsp process hangs forever

Notes

The code on line 198 tries to join a thread and eats any error that shows up without reporting it. If I change the code to print the error value, it's Err(Any), which I guess isn't useful.

If I build in debug mode instead of release mode, I get a different set of messages, and kak-lsp exits cleanly:

Mar 27 12:53:03.062 INFO Starting main event loop, module: kak_lsp::session:31


Mar 27 12:53:07.220 INFO Starting Language server `pyls `, module: kak_lsp::language_server_transport:19
thread '<unnamed>' panicked at 'Failed to start language server: Os { code: 2, kind: NotFound, message: "No such file or directory" }', src/libcore/result.rs:997:5
note: Run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
Mar 27 12:53:07.221 ERRO Failed to join controller thread, module: kak_lsp::session:75
Mar 27 12:53:07.223 INFO Starting Language server `pyls `, module: kak_lsp::language_server_transport:19
thread '<unnamed>' panicked at 'Failed to start language server: Os { code: 2, kind: NotFound, message: "No such file or directory" }', src/libcore/result.rs:997:5
Mar 27 12:53:07.224 ERRO Failed to join controller thread, module: kak_lsp::session:75
Mar 27 12:53:07.281 INFO Starting Language server `pyls `, module: kak_lsp::language_server_transport:19
thread '<unnamed>' panicked at 'Failed to start language server: Os { code: 2, kind: NotFound, message: "No such file or directory" }', src/libcore/result.rs :997:5
Mar 27 12:53:07.282 ERRO Failed to join controller thread, module: kak_lsp::session:75


Mar 27 12:53:09.696 INFO Shutting down language servers and exiting, module: kak_lsp::session:191

(line-breaks added at the times when Kakoune is launched and exits)

If I change the code to unconditionally unwrap the thread result (i.e. propagating the panic), the release build prints nothing useful, but exits cleanly:

Mar 27 12:58:23.933 INFO Starting main event loop, module: kak_lsp::session:31


Mar 27 12:58:29.663 INFO Starting Language server `pyls `, module: kak_lsp::language_server_transport:19
thread '<unnamed>' panicked at 'Failed to start language server: Os { code: 2, kind: NotFound, message: "No such file or directory" }', src/libcore/result.rs:997:5
note: Run with `RUST_BACKTRACE=1` environment variable to display a backtrace.


thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Any', src/libcore/result.rs:997:5
Mar 27 12:58:32.455 INFO Shutting down language servers and exiting, module: kak_lsp::session:191

...while the debug build behaves pretty much the same as ever.

Screwtapello avatar Mar 27 '19 02:03 Screwtapello

Does this problem persist on the latest master? I think fixing #144 might resolve it.

ul avatar Jul 18 '19 10:07 ul

I built kak-lsp revision 789de5c using Rust 1.36.0.

When building in release mode, and following the reproduction steps:

  • After starting kak-lsp, starting kak prints the expected message about being unable to start the language server:

    Jul 20 17:32:12.189 INFO Starting Language server `pyls `, module: kak_lsp::language_server_transport:19
thread 'Controller' panicked at 'Failed to start language server: Os { code: 2, kind: NotFound, message: "No such file or directory" }', src/libcore/result.rs:999:5
note: Run with `RUST_BACKTRACE=1` environment variable to display a backtrace.

  • When quitting kak, kak-lsp prints more messages, and fails to exit:

    thread 'main' panicked at 'Box<Any>', src/thread_worker.rs:29:17
Jul 20 17:33:09.199 INFO Shutting down language servers and exiting, module: kak_lsp::session:166
Jul 20 17:33:09.199 INFO Exit python in project /home/st/foo.py, module: kak_lsp::session:171
Jul 20 17:33:09.199 INFO Waiting for Controller to finish..., module: kak_lsp::thread_worker:18
Jul 20 17:33:09.199 INFO ... Controller terminated with err, module: kak_lsp::thread_worker:20
Jul 20 17:33:09.199 INFO Waiting for Messages from editor to finish..., module: kak_lsp::thread_worker:18

  • If I start another kak to connect to kak-lsp, it prints more messages:

    Jul 20 17:34:58.594 INFO ... Messages from editor terminated with ok, module: kak_lsp::thread_worker:20
Jul 20 17:34:58.594 INFO Waiting for Messages to editor to finish..., module: kak_lsp::thread_worker:18

  • ...but when quitting kak a second time, no new messages are produced.

When building in debug mode:

  • After starting kak-lsp, starting kak prints the expected message about being unable to start the language server, just like release mode, but then prints more messages:

    thread 'main' panicked at 'Box<Any>', src/thread_worker.rs:29:17
Jul 20 17:41:11.951 INFO Waiting for Controller to finish..., module: kak_lsp::thread_worker:18
Jul 20 17:41:11.951 INFO ... Controller terminated with err, module: kak_lsp::thread_worker:20
Jul 20 17:41:11.951 INFO Waiting for Messages from editor to finish..., module: kak_lsp::thread_worker:18
Jul 20 17:41:12.024 INFO ... Messages from editor terminated with ok, module: kak_lsp::thread_worker:20
Jul 20 17:41:12.024 INFO Waiting for Messages to editor to finish..., module: kak_lsp::thread_worker:18
Jul 20 17:41:12.025 INFO ... Messages to editor terminated with ok, module: kak_lsp::thread_worker:20

  • When quitting kak, kak-lsp has already exited, so prints nothing more.

If I set RUST_BACKTRACE=1 to check out that "thread 'main' panicked" message, it gets mixed up with the output logging. If I turn down the verbosity in the config file, it still gets a bit messed up, but it's more readable:

<kak_lsp::thread_worker::ScopedThread as core::ops::drop::Drop>::drop at src/thread_worker.rs:29 
thread 'main' panicked at 'Box<Any>', src/thread_worker.rs:29:17
stack backtrace:
   0: std::sys::unix::Julbacktrace::tracing:: imp::20unwind_backtrace 
17           :  at 46src/libstd/sys/unix/backtrace/tracing/gcc_s.rs::3914
.  450 1: std::sys_common::backtrace::_print 
             at src/libstd/sys_common/backtrace.rs:71
   2: std::panickingERRO::default_hook::{{ closure}}
           Failed to send stop message to language server  at src/libstd/sys_common/backtrace.rs:59
             at src/libstd/panicking.rs:197
,    3: modulestd::panicking::default_hook:
             at src/libstd/panicking.rs :211
  kak_lsp::session:169 4: std::panicking::rust_panic_with_hook

             at src/libstd/panicking.rs:474
   5: std::panicking::begin_panic
             at /rustc/a53f9df32fbb0b5f4382caaad8f1a46f36ea887c/src/libstd/panicking.rs:408
   6: <kak_lsp::thread_worker::ScopedThread as core::ops::drop::Drop>::drop
             at src/thread_worker.rs:29
   7: core::ptr::real_drop_in_place
             at /rustc/a53f9df32fbb0b5f4382caaad8f1a46f36ea887c/src/libcore/ptr.rs:195
   8: core::ptr::real_drop_in_place
             at /rustc/a53f9df32fbb0b5f4382caaad8f1a46f36ea887c/src/libcore/ptr.rs:195
   9: core::ptr::real_drop_in_place
             at /rustc/a53f9df32fbb0b5f4382caaad8f1a46f36ea887c/src/libcore/ptr.rs:195
  10: kak_lsp::session::stop_session
             at src/session.rs:172
  11: kak_lsp::session::start
             at src/session.rs:128
  12: kak_lsp::main
             at src/main.rs:203
  13: std::rt::lang_start::{{closure}}
             at /rustc/a53f9df32fbb0b5f4382caaad8f1a46f36ea887c/src/libstd/rt.rs:64
  14: std::panicking::try::do_call
             at src/libstd/rt.rs:49
             at src/libstd/panicking.rs:293
  15: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:85
  16: std::rt::lang_start_internal
             at src/libstd/panicking.rs:272
             at src/libstd/panic.rs:394
             at src/libstd/rt.rs:48
  17: std::rt::lang_start
             at /rustc/a53f9df32fbb0b5f4382caaad8f1a46f36ea887c/src/libstd/rt.rs:64
  18: main
  19: __libc_start_main
  20: _start

Screwtapello avatar Jul 20 '19 07:07 Screwtapello