Frequent crashes after updating neovim from 0.9.5 to 0.10.1

[jadahl]

When editing code, it often crashes and logs

 [2024-09-06T11:17:51Z ERROR nvim_gtk::shell] Error reading message

and nothing else.

Technical information:

• OS: Fedora 40
• Neovim version: 0.10.1
• Neovim-Gtk build version: main branch as of today (Sep 06)

[Lyude]

Does this happen when you're doing tab completion (also, what does RUST_BACKTRACE=1 say?)

[Lyude]

Also JFYI - it might be worth updating and trying the changes I'm going to push in just a moment. I started being able to reliably crash neovim-gtk with some rust code, and eventually traced the problem down to nvim-rs being a bit out of date - resulting in us panicking because we're getting return values from neovim's API that we're not expecting....

EDIT: nevermind, it's still a problem it seems. I'm a little stumped on what's happening here - it seems like rpmv is returning an error saying it can't properly decode a message being received, but I can't seem to figure out why that is. I'm almost worried this might be a neovim bug, but I'll have to keep looking :s.

In the mean time I wrote up a quick workaround in my local branch that I'm going to try out and push if it ends up working around the problem.

[Lyude]

Mind seeing if this helps at all? https://github.com/Lyude/neovim-gtk/tree/wip/nvim-rpc-wrong-type-workaround

[Lyude]

OK - I think I might be a bit closer to understanding what's happening after seeing this a few times. I think this might have some kind of relation to how we're informing neovim about the bounds of popups, but I'll have to take a closer look soon.

[Lyude]

Try this branch https://github.com/Lyude/neovim-gtk/tree/wip/input-crash
I'm still not certain but I've got yet to run into any crashes quite yet using this

[marcelometal]

Maybe the following backtrace can help...

Using:

NVIM v0.10.2
Build type: Release
LuaJIT 2.1.1713484068
Run "nvim -V1 -v" for more info

with branch main and these two patches:

• https://github.com/Lyude/neovim-gtk/tree/wip/input-crash
• https://github.com/Lyude/neovim-gtk/tree/wip/nvim-rpc-wrong-type-workaround

I got this backtrace:

[2024-10-29T03:25:57Z ERROR nvim_gtk::shell] Error reading message
[2024-10-29T03:25:57Z ERROR nvim_gtk::nvim::ext] Error in last Neovim request: Error decoding response to request 'nvim_input_mouse'
[2024-10-29T03:25:57Z ERROR nvim_gtk::nvim::ext] Caused by: Some(InvalidMessage(NotAnArray(Map([(String(Utf8String { s: Ok("kind") }), String(Utf8String { s: Ok("syntax") })), (String(Utf8String { s: Ok("hi_name") }), String(Utf8String { s: Ok("LineNr") })), (String(Utf8String { s: Ok("id") }), Integer(PosInt(406)))]))))
thread 'main' panicked at src/shell.rs:1444:10:
Can't send mouse input event
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread 'main' panicked at core/src/panicking.rs:221:5:
panic in a function that cannot unwind
stack backtrace:
   0:     0x562fa663c866 - std::backtrace_rs::backtrace::libunwind::trace::h4d7259b7081c1434
                               at /usr/src/rustc-1.82.0/library/std/src/../../backtrace/src/backtrace/libunwind.rs:116:5
   1:     0x562fa663c866 - std::backtrace_rs::backtrace::trace_unsynchronized::hdff17bc91d81c84f
                               at /usr/src/rustc-1.82.0/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x562fa663c866 - std::sys::backtrace::_print_fmt::hc4981bfcc87d456c
                               at /usr/src/rustc-1.82.0/library/std/src/sys/backtrace.rs:66:9
   3:     0x562fa663c866 - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::h656f806fa3938fe8
                               at /usr/src/rustc-1.82.0/library/std/src/sys/backtrace.rs:39:26
   4:     0x562fa6676ccb - core::fmt::rt::Argument::fmt::h83e0617c3c9896b7
                               at /usr/src/rustc-1.82.0/library/core/src/fmt/rt.rs:177:76
   5:     0x562fa6676ccb - core::fmt::write::hdfd2d12c94f4f8c5
                               at /usr/src/rustc-1.82.0/library/core/src/fmt/mod.rs:1178:21
   6:     0x562fa6656e3f - std::io::Write::write_fmt::h1c3987cbd20d1037
                               at /usr/src/rustc-1.82.0/library/std/src/io/mod.rs:1823:15
   7:     0x562fa66387f2 - std::sys::backtrace::BacktraceLock::print::h6d7097db9341c0a1
                               at /usr/src/rustc-1.82.0/library/std/src/sys/backtrace.rs:42:9
   8:     0x562fa66387f2 - std::panicking::default_hook::{{closure}}::h00666f2c4dc1c081
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:266:22
   9:     0x562fa66383b9 - std::panicking::default_hook::h9d901dc0b2662d53
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:293:9
  10:     0x562fa6638f9f - std::panicking::rust_panic_with_hook::h89a424cfa4648a56
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:797:13
  11:     0x562fa663cc33 - std::panicking::begin_panic_handler::{{closure}}::hd30b2d43f9bb4cd0
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:664:13
  12:     0x562fa663ca99 - std::sys::backtrace::__rust_end_short_backtrace::h791fba3dd0e0dd24
                               at /usr/src/rustc-1.82.0/library/std/src/sys/backtrace.rs:170:18
  13:     0x562fa6638a04 - rust_begin_unwind
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:662:5
  14:     0x562fa5bc8f85 - core::panicking::panic_nounwind_fmt::runtime::ha0e267f95ae7575e
                               at /usr/src/rustc-1.82.0/library/core/src/panicking.rs:112:18
  15:     0x562fa5bc8f85 - core::panicking::panic_nounwind_fmt::h076e449a239f7521
                               at /usr/src/rustc-1.82.0/library/core/src/panicking.rs:122:5
  16:     0x562fa5bc9012 - core::panicking::panic_nounwind::he18c314394f435c8
                               at /usr/src/rustc-1.82.0/library/core/src/panicking.rs:221:5
  17:     0x562fa5bc9236 - core::panicking::panic_cannot_unwind::h4e7845e5618a22b1
                               at /usr/src/rustc-1.82.0/library/core/src/panicking.rs:310:5
  18:     0x562fa5f63565 - gtk4::auto::event_controller_scroll::EventControllerScroll::connect_scroll::scroll_trampoline::h1948b720134c1a68
                               at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/gtk4-0.9.2/src/auto/event_controller_scroll.rs:101:9
  19:     0x7f35590d3dde - <unknown>
  20:     0x7f3559abfbc9 - <unknown>
  21:     0x7f3559ad58f8 - <unknown>
  22:     0x7f3559adb666 - g_signal_emit_valist
  23:     0x7f3559adb723 - g_signal_emit
  24:     0x7f3559160441 - <unknown>
  25:     0x7f355915deee - <unknown>
  26:     0x7f35592b8cec - <unknown>
  27:     0x7f35591d229e - <unknown>
  28:     0x7f35591d2803 - <unknown>
  29:     0x7f3559453082 - <unknown>
  30:     0x7f35594e841d - <unknown>
  31:     0x7f3559abfbc9 - <unknown>
  32:     0x7f3559ad4b73 - <unknown>
  33:     0x7f3559adb666 - g_signal_emit_valist
  34:     0x7f3559adb723 - g_signal_emit
  35:     0x7f35594ec1f4 - <unknown>
  36:     0x7f35594c94b9 - <unknown>
  37:     0x7f35594ec57b - <unknown>
  38:     0x7f3559abfbc9 - <unknown>
  39:     0x7f3559ad58f8 - <unknown>
  40:     0x7f3559adb666 - g_signal_emit_valist
  41:     0x7f3559adb723 - g_signal_emit
  42:     0x7f35594d022b - <unknown>
  43:     0x7f3558bd188e - <unknown>
  44:     0x7f3558bce7df - <unknown>
  45:     0x7f3558bd0a17 - <unknown>
  46:     0x7f3558bd1180 - g_main_context_iteration
  47:     0x7f3558dab445 - g_application_run
  48:     0x562fa5c088b2 - gio::application::ApplicationExtManual::run_with_args::h7f5543a8e548ad13
                               at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/gio-0.20.4/src/application.rs:29:13
  49:     0x562fa5c08999 - gio::application::ApplicationExtManual::run::h73016d52c66fa230
                               at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/gio-0.20.4/src/application.rs:22:9
  50:     0x562fa5cda10b - nvim_gtk::main::hd05cf307d8b4edf9
                               at /home/metal/work/neovim-gtk/src/main.rs:344:5
  51:     0x562fa5dbe63b - core::ops::function::FnOnce::call_once::ha5459bc7e5d61649
                               at /usr/src/rustc-1.82.0/library/core/src/ops/function.rs:250:5
  52:     0x562fa5c9258e - std::sys::backtrace::__rust_begin_short_backtrace::h94ad0580ee3af847
                               at /usr/src/rustc-1.82.0/library/std/src/sys/backtrace.rs:154:18
  53:     0x562fa5bdd801 - std::rt::lang_start::{{closure}}::habce87b47dbd869b
                               at /usr/src/rustc-1.82.0/library/std/src/rt.rs:164:18
  54:     0x562fa6637a25 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h4db63d72da403279
                               at /usr/src/rustc-1.82.0/library/core/src/ops/function.rs:284:13
  55:     0x562fa6637a25 - std::panicking::try::do_call::hb7ac7f0f5030566c
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:554:40
  56:     0x562fa6637a25 - std::panicking::try::ha289534029f94113
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:518:19
  57:     0x562fa6637a25 - std::panic::catch_unwind::hb8fccf0d17e787a5
                               at /usr/src/rustc-1.82.0/library/std/src/panic.rs:345:14
  58:     0x562fa6637a25 - std::rt::lang_start_internal::{{closure}}::hfdb74a1fa288eefc
                               at /usr/src/rustc-1.82.0/library/std/src/rt.rs:143:48
  59:     0x562fa6637a25 - std::panicking::try::do_call::h1748c7eaeec30b8e
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:554:40
  60:     0x562fa6637a25 - std::panicking::try::h26aae36ddfb82e25
                               at /usr/src/rustc-1.82.0/library/std/src/panicking.rs:518:19
  61:     0x562fa6637a25 - std::panic::catch_unwind::h71a6cac111f9f7ef
                               at /usr/src/rustc-1.82.0/library/std/src/panic.rs:345:14
  62:     0x562fa6637a25 - std::rt::lang_start_internal::hbe7e94a367a53126
                               at /usr/src/rustc-1.82.0/library/std/src/rt.rs:143:20
  63:     0x562fa5bdd7da - std::rt::lang_start::h16bb6570d17ebc9a
                               at /usr/src/rustc-1.82.0/library/std/src/rt.rs:163:17
  64:     0x562fa5cde22e - main
  65:     0x7f3558894d68 - __libc_start_call_main
                               at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
  66:     0x7f3558894e25 - __libc_start_main_impl
                               at ./csu/../csu/libc-start.c:360:3
  67:     0x562fa5bc9be1 - _start
  68:                0x0 - <unknown>
thread caused non-unwinding panic. aborting.

[Lyude]

@marcelometal a bit, but I could use someone else trying the branch I just pushed. I -think- I actually have it this time, I made it so we do this call synchronously and since then I haven't had any crashes over the last few weeks: https://github.com/Lyude/neovim-gtk/tree/wip/input-crash
Give the updated branch another try and let me know

[jadahl]

I just upgraded to F41 and that upgraded my nvim, so ran into this again (sorry for not testing earlier). I just make install:ed 21b93a1 from wip/input-crash, and I still get

[2024-11-04T21:12:47Z ERROR nvim_gtk::shell] Error reading message

I was running with RUST_BACKTRACE=1 but it didn't show anything extra.

I'm not getting it when auto-completing now, it happened when I tried to backspace erase some code in a file I had open.

[Lyude]

So I think it may be a race condition of some sort still, because my previous fix definitely lowered how often this problem happens but I managed to just hit it again myself

[jadahl]

I can reproduce it at will, as soon as I press backspace in my session I usually :source, so I can gather any debug info you need, if you want. I'm using the same session file from nvim from a terminal for the time being, without issues.

[Lyude]

@jadahl Oh! That's super useful
If you could: run nvim-gtk like this:

RUST_LOG=nvim_rs,nvim_gtk nvim-gtk $ARGS

And get me the output that comes up from right when things crash, that should tell me what kind of interactions are actually causing this with neovim

[Lyude]

fhsjhsdfjhdsjfakfdhsdjafh oh i hate this
I finally figured out what's going on. It is a race condition in neovim, I tracked it down to this commit:

commit dc37c1550bed46fffbb677d343cdc5bc94056219 (HEAD)
Author: bfredl <[email protected]>
Date:   Sun Feb 25 15:02:48 2024 +0100

    refactor(msgpack): allow flushing buffer while packing msgpack
    
    Before, we needed to always pack an entire msgpack_rpc Object to
    a continous memory buffer before sending it out to a channel.
    But this is generally wasteful. it is better to just flush
    whatever is in the buffer and then continue packing to a new buffer.
    
    This is also done for the UI event packer where there are some extra logic
    to "finish" of an existing batch of nevents/ncalls. This doesn't really
    stop us from flushing the buffer, just that we need to update the state
    machine accordingly so the next call to prepare_call() always will
    start with a new event (even though the buffer might contain overflow
    data from a large event).

I'm going to file a bug and reference this here

[Lyude]

neovim/neovim#31316

OK so - right now we need to come up with the simplest reproducer possible for this problem. If anyone has a very basic config with neovim-gtk that can trigger this, please let the people in this issue know about it! I'm going to try my best to come up with something before thanksgiving or after that hopefully the folks over at neovim can use to see the issue on their end.