Rls: "Out of order or duplicate change" panic

[sfackler]

This seems to happen around the same context as things like #749 - when you keep modifying things in a big workspace while RLS is working.

thread 'main' panicked at 'Out of order or duplicate change', tools/rls/src/actions/mod.rs:267: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::server::LsService<O>>::dispatch_message
   9: rls::main
  10: std::rt::lang_start::{{closure}}
  11: std::panicking::try::do_call
  12: __rust_maybe_catch_panic
  13: std::rt::lang_start_internal
  14: main
[Info  - 2:29:34 PM] Connection to server got closed. Server will restart.

Interestingly, I start seeing BadLocation errors immediately after that:

thread 'main' panicked at 'error committing to VFS: BadLocation', libcore/result.rs:945:5
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: std::panicking::rust_panic_with_hook
   5: std::panicking::begin_panic_fmt
   6: rust_begin_unwind
   7: core::panicking::panic_fmt
   8: core::result::unwrap_failed
   9: <rls::server::LsService<O>>::dispatch_message
  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
[Info  - 2:29:35 PM] Connection to server got closed. Server will restart.

[nrc]

This means that we're handling 'TextDocument/didChange' notifications out of order, which is a big we can't really recover from. Either the client is sending the messages out of order (in which case there is nothing we can do) or our buffering of messages is going wrong.

The bad location errors are almost certainly a knock-on effect of the out of order notifications - it'll put the VFS into an inconsistent state.

[Marwes]

Seeing this with https://github.com/autozimu/LanguageClient-neovim (see https://github.com/autozimu/LanguageClient-neovim/issues/320).

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

[nrc]

This should be fixed on master now.

[OnlyLys]

Hi @nrc, it appears I still have this problem in the latest nightly as well as stable. It happens anywhere for me in VSCode, all that it takes is for me to backspace or make some changes while RLS is trying to run and it will crash.

On nightly it prints:

thread 'main' panicked at 'Out of order or duplicate change', tools\rls\src\actions\mod.rs:270:13

Whereas on stable it is:

thread 'main' panicked at 'Out of order or duplicate change', tools\rls\src\actions\mod.rs:272:13

Curiously, this problem only seems to have surfaced in the past 48 hours for me. In that time, I noticed that the VSCode extension has had a patch version bump and so it may be related to that or it may not.

[nrc]

@OnlyLys have you tried with master? There is currently a PR to update nightly, so you this should be fixed soon (maybe tomorrow's nightly? Maybe the next day).

[OnlyLys]

Thank you for the update @nrc. I haven't tried with master actually, I incorrectly assumed that the changes have been reflected in nightly, my bad!

I'll give the latest update a try in a day or two and report back.

[OnlyLys]

Hi @nrc, so I tried out the new changes in the latest Rust nightly toolchain (which includes the previously mentioned https://github.com/rust-lang/rust/commit/3b1fa867f2d053102c2f0effc4b81424bf97866b) and I'm still getting the out of order issues.

I also tried specifying rust-client.channel = "nightly" in VSCode to be doubly sure, and sadly the out of order problem is there ☹.

[chipp]

Hello @nrc!

I downgraded to vscode extension version 0.4.0 and it works now without any crash. But on v0.4.1 it crashes the same as @OnlyLys mentioned above.

[OnlyLys]

@nrc

Ok so, based on what @chipp said, I did some digging around the rls-vscode repo and narrowed down the issue to this specific merge commit: https://github.com/rust-lang-nursery/rls-vscode/commit/75c5e7ac6a8644ea67c9ff952eff7c71d0be8453 that updated some dependencies.

From that commit onwards, the out of order issues happen, even with the latest RLS. That said I noticed something that could help determine what the cause is:

What I observed was that out of order issues always follow PoisonErrors (https://github.com/rust-lang-nursery/rls/issues/750), and they are triggered the same way: by interrupting RLS while it is working.

However, prior to the commit mentioned above (75c5e7a), a single PoisonError was able to cause the VS Code extension to malfunction (but not crash - it just kind of freezes so my code was no longer being analysed on the fly). So there's no way to observe if out of order issues can occur after that because the extension stops working at the first PoisonError.

But after commit (75c5e7a), PoisonErrors do not immediately freeze the extension, and thus I am able to trigger the out of order issues which follow that. The out of order issues then proceed to crash the RLS.

Hopefully someone can try it out and confirm my observations.

[OnlyLys]

Good news @nrc, the recent commit you made (https://github.com/rust-lang-nursery/rls/commit/1d8a5a3befc955d6b027ffa76d129f97b164ad54) seems to have fixed the Out of Order and PoisonError issues for me. I am unable to intentionally trigger the crash now.

[nrc]

Awesome thanks for checking that out!