Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Crashes when write-quitting a large file. #3975

Closed
2gn opened this issue Sep 26, 2022 · 19 comments · Fixed by #2267
Closed

Crashes when write-quitting a large file. #3975

2gn opened this issue Sep 26, 2022 · 19 comments · Fixed by #2267
Labels
C-bug Category: This is a bug

Comments

@2gn
Copy link

2gn commented Sep 26, 2022

Summary

I edited all-packages.nix and tried to wq! the changes, but it crashed.

Reproduction Steps

I tried this:

  1. hx a large file
  2. make some changes
  3. save

I expected this to happen:

write and quit successfully

Instead, this happened:

crash

Helix log

~/.cache/helix/helix.log
please provide a copy of `~/.cache/helix/helix.log` here if possible, you may need to redact some of the lines

2022-08-11T17:51:09.180 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:02:59.187 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:10:09.368 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:19:07.553 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:20:46.524 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:21:17.593 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:21:28.013 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:22:41.642 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:23:00.811 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T13:27:50.334 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:02:50.084 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:03:02.851 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:03:17.048 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:03:46.285 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:04:05.917 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:04:09.012 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:04:27.585 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:05:12.935 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:06:16.331 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:06:40.632 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:06:58.853 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:08:24.472 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-12T14:11:18.176 helix_view::editor [ERROR] Failed to initialize the LSP for source.python { cannot find binary path }
2022-08-12T14:11:46.861 helix_view::editor [ERROR] Failed to initialize the LSP for source.python { cannot find binary path }
2022-08-12T17:33:47.568 helix_view::editor [ERROR] Failed to initialize the LSP for source.python { cannot find binary path }
2022-08-12T18:24:56.068 helix_view::editor [ERROR] Failed to initialize the LSP for source.python { cannot find binary path }
2022-08-12T18:24:59.526 helix_view::theme [WARN] Theme: invalid style attribute: modifier
2022-08-21T09:31:31.775 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-27T10:32:51.516 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-27T10:33:25.851 helix_view::editor [ERROR] Failed to initialize the LSP for source.nix { cannot find binary path }
2022-08-27T10:34:17.362 helix_view::editor [ERROR] Failed to initialize the LSP for source.rust { cannot find binary path }
2022-08-27T10:35:43.738 helix_view::editor [ERROR] Failed to initialize the LSP for source.rust { cannot find binary path }
2022-08-27T10:44:11.667 helix_view::editor [ERROR] Failed to initialize the LSP for source.toml { LSP not defined }
2022-08-27T10:51:06.627 helix_view::editor [ERROR] Failed to initialize the LSP for source.toml { LSP not defined }
2022-08-27T10:52:26.643 helix_view::editor [ERROR] Failed to initialize the LSP for source.toml { LSP not defined }
2022-08-27T10:53:31.533 helix_view::editor [ERROR] Failed to initialize the LSP for source.rust { cannot find binary path }
2022-08-27T10:54:59.525 helix_view::editor [ERROR] Failed to initialize the LSP for source.rust { cannot find binary path }
2022-09-03T17:48:27.488 helix_view::editor [ERROR] Failed to initialize the LSP for source.python { cannot find binary path }
2022-09-03T21:52:56.231 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-03T21:52:56.231 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-03T21:53:01.254 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-03T21:53:01.254 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-14T16:04:25.430 helix_view::clipboard::provider [WARN] No clipboard provider found! Yanking and pasting will be internal to Helix
2022-09-15T09:27:38.298 helix_view::clipboard::provider [WARN] No clipboard provider found! Yanking and pasting will be internal to Helix
2022-09-15T11:19:07.376 helix_view::clipboard::provider [WARN] No clipboard provider found! Yanking and pasting will be internal to Helix
2022-09-15T11:25:39.736 helix_view::clipboard::provider [WARN] No clipboard provider found! Yanking and pasting will be internal to Helix
2022-09-25T16:29:22.423 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-25T16:29:22.423 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-25T16:34:19.694 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-25T16:34:19.694 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:30:33.370 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:30:33.370 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:35:12.982 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:35:12.982 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:35:28.484 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:35:28.484 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:35:58.156 helix_lsp::transport [ERROR] err: <- StreamClosed
2022-09-26T15:35:58.156 helix_lsp::transport [ERROR] err: <- StreamClosed

Platform

Linux

Terminal Emulator

gnome-terminal

Helix Version

helix 22.08 (ee94031)

@2gn 2gn added the C-bug Category: This is a bug label Sep 26, 2022
@the-mikedavis
Copy link
Member

Can you post a backtrace from the panic?

@2gn
Copy link
Author

2gn commented Sep 27, 2022

I couldn't quit helix by Ctrl+C or Ctrl+D. It just freezes in the terminal. Terminal emulator's window and buttons were clickable so I quit the program using close button.
The file was successfully modified after the force-quit though.

@the-mikedavis
Copy link
Member

Do you have rnix-lsp installed?

@Ordoviz
Copy link
Contributor

Ordoviz commented Sep 28, 2022

I get a freeze on :wq but not on :wq!. Reverting 41bf1d5 fixes it and the write still succeeds.

@2gn
Copy link
Author

2gn commented Sep 28, 2022

Do you have rnix-lsp installed?

yes

I get a freeze on :wq but not on :wq!. Reverting 41bf1d5 fixes it and the write still succeeds.

Interesting. Maybe I should use wq! instead of wq for now. Thank you!

@dead10ck
Copy link
Member

Could you please run hx -vvvv and reproduce the bug, and provide your helix.log from that?

@Ordoviz
Copy link
Contributor

Ordoviz commented Sep 28, 2022

Only helix_term::job [DEBUG] waiting on jobs... is printed to the log file after :wq. rnix-lsp is not installed.

@dead10ck
Copy link
Member

There should be a lot more than that with -vvvv (4 vs for trace level logging)

@dead10ck
Copy link
Member

dead10ck commented Sep 28, 2022

Also you mentioned it crashed; could you run it with RUST_BACKTRACE=full and paste the backtrace?

@Ordoviz
Copy link
Contributor

Ordoviz commented Sep 28, 2022

There should be a lot more than that with -vvvv (4 vs for trace level logging)

Nope, it's just this:

2022-09-28T22:34:29.967 helix_view::editor [ERROR] Failed to initialize the LSP for `source.nix` { cannot find binary path }
2022-09-28T22:34:29.967 mio::poll [TRACE] registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
2022-09-28T22:34:29.967 mio::poll [TRACE] registering event source with poller: token=Token(2), interests=READABLE | WRITABLE
2022-09-28T22:34:29.968 mio::poll [TRACE] registering event source with poller: token=Token(0), interests=READABLE
2022-09-28T22:34:29.968 mio::poll [TRACE] registering event source with poller: token=Token(1), interests=READABLE
2022-09-28T22:34:40.468 helix_term::job [DEBUG] waiting on jobs...

Helix freezes and consumes 100% CPU doing ... something, but not making any system calls (as shown by strace).

@dead10ck
Copy link
Member

Interesting... Are you able to do anything with the file at all? Can you navigate, make changes, etc? Or is it just completely unresponsive? You could just be running into #338

@dead10ck
Copy link
Member

Actually I just tried this myself, and I'm not experiencing this problem. It writes and quits almost instantly. From the sound of it, this it not a crash, but a hang. Would you be able to run it through lldb or a profiler to see what it's doing?

@Ordoviz
Copy link
Contributor

Ordoviz commented Sep 29, 2022

This freezes Helix:

$ git clone https://github.com/helix-editor/helix && cd helix
$ python -c 'print("A"*1040384)' > toobig
$ python -c 'print("A"*1040383)' > thisisfine
$ cargo run -- toobig
:wq

Open another terminal to debug:

$ sudo lldb -p $(pidof hx)
(lldb) bt

The part of the stack above helix_term::job::Jobs::finish is different every time:

Backtrace 1:
* thread #1, name = 'hx', stop reason = signal SIGSTOP
  * frame #0: 0x000055ede94abaf5 hx`_$LT$futures_util..stream..futures_unordered..FuturesUnordered$LT$Fut$GT$$u20$as$u20$futures_core..stream..Stream$GT$::poll_next::hb60b12c49841b7d5(self=Pin<&mut futures_util::stream::futures_unordered::FuturesUnordered + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>>> @ 0x00007ffe3b3dc128, cx=0x00007ffe3b3dc840) at mod.rs:0:35
    frame #1: 0x000055ede94ae329 hx`futures_util::stream::stream::StreamExt::poll_next_unpin::hfeba604814f19805(self=0x00007ffe3b3dc9c8, cx=0x00007ffe3b3dc840) at mod.rs:1626:9
    frame #2: 0x000055ede95ebf53 hx`_$LT$futures_util..stream..stream..into_future..StreamFuture$LT$St$GT$$u20$as$u20$core..future..future..Future$GT$::poll::hdf2142a5bf75e447(self=Pin<&mut futures_util::stream::stream::into_future::StreamFuture + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>>>> @ 0x00007ffe3b3dc3a8, cx=0x00007ffe3b3dc840) at into_future.rs:85:20
    frame #3: 0x000055ede92182e3 hx`helix_term::job::Jobs::finish::_$u7b$$u7b$closure$u7d$$u7d$::h6a3d01600b4f0a0b((null)=ResumeTy @ 0x00007ffe3b3dc700) at job.rs:99:65
Backtrace 2:
* thread #1, name = 'hx', stop reason = signal SIGSTOP
  * frame #0: 0x000055c70b65cb2a hx`core::mem::replace::hd410bd88f73edc57(dest=0x000055c70dd3c720, src=Option @ 0x00007ffcf420df4f) at mod.rs:918:22
    frame #1: 0x000055c70b64c5c9 hx`core::option::Option$LT$T$GT$::take::h225963ce727c38ef(self=0x000055c70dd3c720) at option.rs:1576:9
    frame #2: 0x000055c70b631553 hx`tokio::fs::file::Inner::poll_flush::h7d8c18ab8f0cb43c(self=0x000055c70dd3c6f0, cx=0x00007ffcf4215e28) at file.rs:759:26
    frame #3: 0x000055c70b6314fc hx`_$LT$tokio..fs..file..File$u20$as$u20$tokio..io..async_write..AsyncWrite$GT$::poll_flush::h540e589dca1617f2(self=Pin<&mut tokio::fs::file::File> @ 0x00007ffcf420e2d0, cx=0x00007ffcf4215e28) at file.rs:699:9
    frame #4: 0x000055c70a9bf734 hx`_$LT$$RF$mut$u20$T$u20$as$u20$tokio..io..async_write..AsyncWrite$GT$::poll_flush::h392705a1bf15069d(self=Pin<&mut &mut tokio::fs::file::File> @ 0x00007ffcf420e320, cx=0x00007ffcf4215e28) at async_write.rs:208:13
    frame #5: 0x000055c70ae9acb4 hx`_$LT$tokio..io..util..flush..Flush$LT$A$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h8b3a56ffb238120b(self=Pin<&mut tokio::io::util::flush::Flush> @ 0x00007ffcf420e380, cx=0x00007ffcf4215e28) at flush.rs:44:9
    frame #6: 0x000055c70ad7df45 hx`helix_view::document::to_writer::_$u7b$$u7b$closure$u7d$$u7d$::ha0039f91534a8a23((null)=ResumeTy @ 0x00007ffcf420e848) at document.rs:317:27
    frame #7: 0x000055c70aab114e hx`_$LT$core..future..from_generator..GenFuture$LT$T$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h36bea85ef4f56c0d(self=Pin<&mut core::future::from_generator::GenFuture>> @ 0x00007ffcf420e958, cx=0x00007ffcf4215e28) at mod.rs:91:19
    frame #8: 0x000055c70ad7c422 hx`helix_view::document::Document::save_impl::_$u7b$$u7b$closure$u7d$$u7d$::hc5b3af98e133bb81((null)=ResumeTy @ 0x00007ffcf42136b8) at document.rs:563:50
    frame #9: 0x000055c70aab2e4e hx`_$LT$core..future..from_generator..GenFuture$LT$T$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h942a6e0c92bbe2f9(self=Pin<&mut core::future::from_generator::GenFuture> + core::marker::Send), alloc::alloc::Global>>>>>> @ 0x00007ffcf42137e8, cx=0x00007ffcf4215e28) at mod.rs:91:19
    frame #10: 0x000055c70ad2d02f hx`_$LT$futures_util..future..future..map..Map$LT$Fut$C$F$GT$$u20$as$u20$core..future..future..Future$GT$::poll::hd71f2677386681ff(self=(pointer = 0x000055c70dd3c620), cx=0x00007ffcf4215e28) at map.rs:55:37
    frame #11: 0x000055c70ad1a458 hx`_$LT$futures_util..future..future..Map$LT$Fut$C$F$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h16e737cfa63a20ae(self=Pin<&mut futures_util::future::future::Map> + core::marker::Send), alloc::alloc::Global>>>>>, helix_term::job::{impl#0}::new::{closure_env#0}> + core::marker::Send), alloc::alloc::Global>>>>>>>> @ 0x00007ffcf4215af8, cx=0x00007ffcf4215e28) at lib.rs:91:13
    frame #12: 0x000055c70aea0069 hx`_$LT$core..pin..Pin$LT$P$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h97160f0fe280a527(self=Pin<&mut core::pin::Pin + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>> @ 0x00007ffcf4215b40, cx=0x00007ffcf4215e28) at future.rs:124:9
    frame #13: 0x000055c70ad51ea8 hx`_$LT$futures_util..stream..futures_unordered..FuturesUnordered$LT$Fut$GT$$u20$as$u20$futures_core..stream..Stream$GT$::poll_next::hb60b12c49841b7d5(self=Pin<&mut futures_util::stream::futures_unordered::FuturesUnordered + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>>> @ 0x00007ffcf4215d28, cx=0x00007ffcf4216440) at mod.rs:514:17
    frame #14: 0x000055c70ad54329 hx`futures_util::stream::stream::StreamExt::poll_next_unpin::hfeba604814f19805(self=0x00007ffcf42165c8, cx=0x00007ffcf4216440) at mod.rs:1626:9
    frame #15: 0x000055c70ae91f53 hx`_$LT$futures_util..stream..stream..into_future..StreamFuture$LT$St$GT$$u20$as$u20$core..future..future..Future$GT$::poll::hdf2142a5bf75e447(self=Pin<&mut futures_util::stream::stream::into_future::StreamFuture + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>>>> @ 0x00007ffcf4215fa8, cx=0x00007ffcf4216440) at into_future.rs:85:20
    frame #16: 0x000055c70aabe2e3 hx`helix_term::job::Jobs::finish::_$u7b$$u7b$closure$u7d$$u7d$::h6a3d01600b4f0a0b((null)=ResumeTy @ 0x00007ffcf4216300) at job.rs:99:65
Backtrace 3:
* thread #1, name = 'hx', stop reason = signal SIGSTOP
  * frame #0: 0x000055ba40dcdf42 hx`core::ptr::non_null::NonNull$LT$T$GT$::as_ref::hb437c41810fbbea1(self=0x00007ffe7624ec48) at non_null.rs:381:20
    frame #1: 0x000055ba40f56a8f hx`alloc::sync::Arc$LT$T$GT$::inner::hbdf9e5a764f01b82(self=0x00007ffe7624ec48) at sync.rs:1097:18
    frame #2: 0x000055ba40f57dbf hx`_$LT$alloc..sync..Arc$LT$T$GT$$u20$as$u20$core..ops..deref..Deref$GT$::deref::h8429989694cc3319(self=0x00007ffe7624ec48) at sync.rs:1381:10
    frame #3: 0x000055ba40f0e83f hx`futures_util::stream::futures_unordered::FuturesUnordered$LT$Fut$GT$::pending_next_all::h04c9681dc99ad532(self=0x00007ffe7624ec48) at mod.rs:380:22
    frame #4: 0x000055ba40f0e8b0 hx`futures_util::stream::futures_unordered::FuturesUnordered$LT$Fut$GT$::atomic_load_head_and_len_all::h41fc12d55abfa3cf(self=0x00007ffe7624ec48) at mod.rs:233:39
    frame #5: 0x000055ba40f0e92f hx`futures_util::stream::futures_unordered::FuturesUnordered$LT$Fut$GT$::len::h5fa7f14735ab9bb1(self=0x00007ffe7624ec48) at mod.rs:145:24
    frame #6: 0x000055ba40f0d89b hx`_$LT$futures_util..stream..futures_unordered..FuturesUnordered$LT$Fut$GT$$u20$as$u20$futures_core..stream..Stream$GT$::poll_next::hb60b12c49841b7d5(self=Pin<&mut futures_util::stream::futures_unordered::FuturesUnordered + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>>> @ 0x00007ffe7624e3a8, cx=0x00007ffe7624eac0) at mod.rs:388:19
    frame #7: 0x000055ba40f10329 hx`futures_util::stream::stream::StreamExt::poll_next_unpin::hfeba604814f19805(self=0x00007ffe7624ec48, cx=0x00007ffe7624eac0) at mod.rs:1626:9
    frame #8: 0x000055ba4104df53 hx`_$LT$futures_util..stream..stream..into_future..StreamFuture$LT$St$GT$$u20$as$u20$core..future..future..Future$GT$::poll::hdf2142a5bf75e447(self=Pin<&mut futures_util::stream::stream::into_future::StreamFuture + core::marker::Send), alloc::alloc::Global>>, anyhow::Error>> + core::marker::Send), alloc::alloc::Global>>>>> @ 0x00007ffe7624e628, cx=0x00007ffe7624eac0) at into_future.rs:85:20
    frame #9: 0x000055ba40c7a2e3 hx`helix_term::job::Jobs::finish::_$u7b$$u7b$closure$u7d$$u7d$::h6a3d01600b4f0a0b((null)=ResumeTy @ 0x00007ffe7624e980) at job.rs:99:65

@Ordoviz
Copy link
Contributor

Ordoviz commented Sep 29, 2022

This line puts Helix into an infinite loop:

helix_lsp::block_on(cx.jobs.finish())?;

The loop can be found in futures_executor::local_pool::run_executor.

@dead10ck
Copy link
Member

Interesting, thanks for your help debugging! I'm actually fairly confident this is tokio getting into a deadlock (or live lock I suppose) because of this command blocking the runtime. This should actually be fixed in #2267 because it uses another tokio helper meant to avoid this problem with blocking tasks. Would you possibly be able to pull my branch to your machine and test out if this problem persists for you with the changes from there?

@Ordoviz
Copy link
Contributor

Ordoviz commented Sep 29, 2022

#2267 fixes this issue.

@dead10ck
Copy link
Member

#2267 fixes this issue.

Awesome, thanks for testing!

@pauschuu
Copy link

Hello,

I shreddered a very very big config file of mine recently using helix while having this bug.

It's nice to see that it is already fixed but the general question I ask myself is:
Wouldn't it be better to always write into a temporary file and only after a successful write mv (rename) this file to the actual filename (which is atomic on most modern file systems).

@dead10ck
Copy link
Member

@pauschuu see #3967 and #4276. There are a surprising amount of problems with the copy/rename approach.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
C-bug Category: This is a bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants