[GH-ISSUE #349] Librespot locks up when running out of diskspace #229

Closed
opened 2026-02-27 19:29:32 +03:00 by kerem · 1 comment
Owner

Originally created by @matthijskooijman on GitHub (Jul 13, 2019).
Original GitHub issue: https://github.com/librespot-org/librespot/issues/349

I had a machine that was running out of diskspace on /. This does not seem to be handled gracefully. I found an error message in the logs, but then librespot locks up, no longer responds to mdns queries or, I think, server commands.

This was observed with a self-compiled git master version (github.com/librespot-org/librespot@4e3576ba7c)

Here's the error from the log:

[2019-07-13T02:14:19Z INFO  librespot_playback::player] Track "Strobelite (feat. Peven Everett)" loaded
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 28, kind: Other, message: "No space left on device" }', src/libcore/result.r
stack backtrace:
   0:   0xa3637c - backtrace::backtrace::libunwind::trace::hb317fd79f338e9ac
                       at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.29/src/backtrace/libunwind.rs:88
   1:   0xa3637c - backtrace::backtrace::trace_unsynchronized::h577e08d87958ca80
                       at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.29/src/backtrace/mod.rs:66
   2:   0xa3637c - std::sys_common::backtrace::_print::hbfee0f6c5053d54e
                       at src/libstd/sys_common/backtrace.rs:47
   3:   0xa3637c - std::sys_common::backtrace::print::he0aac2b05fe6a451
                       at src/libstd/sys_common/backtrace.rs:36
   4:   0xa3637c - std::panicking::default_hook::{{closure}}::ha2ef00deb6db7a83
                       at src/libstd/panicking.rs:200
   5:   0xa35f2c - std::panicking::default_hook::h641d7e1cec244c78
                       at src/libstd/panicking.rs:214
   6:   0xa36b40 - std::panicking::rust_panic_with_hook::h4043fa8d29430a82
                       at src/libstd/panicking.rs:477
   7:   0xa36704 - std::panicking::continue_panic_fmt::h69e00c7989848347
                       at src/libstd/panicking.rs:384
   8:   0xa365f0 - rust_begin_unwind
                       at src/libstd/panicking.rs:311
   9:   0xa52adc - core::panicking::panic_fmt::h368b1e08709edc0e
                       at src/libcore/panicking.rs:85
  10:   0x6815e0 - core::result::unwrap_failed::hb36bb57d205feb44
  11:   0x6df6b8 - librespot_core::cache::Cache::save_file::h4840fbb770c45ce6
  12:   0x63728c - <futures::future::map::Map<A,F> as futures::future::Future>::poll::hbf2021502e8fa11b
  13:   0x6389cc - futures::future::chain::Chain<A,B,C>::poll::hf56c814a8a30a28e
  14:   0x94eb70 - futures::task_impl::std::set::h0f3a1953102917fd
  15:   0x95b904 - tokio_current_thread::CurrentRunner::set_spawn::hd28e949e3e27e754
  16:   0x955138 - tokio_current_thread::scheduler::Scheduler<U>::tick::h3c9a2fb62e4aa42a
  17:   0x95bbf0 - tokio_current_thread::Entered<P>::turn::h54e4b6ec1a6350ff
  18:   0x94a1fc - scoped_tls::ScopedKey<T>::set::h027fa554916dcb6c
  19:   0x954834 - std::thread::local::LocalKey<T>::with::ha544fc008d9bb431
  20:   0x954be8 - std::thread::local::LocalKey<T>::with::hec21127b56529e20
  21:   0x954398 - std::thread::local::LocalKey<T>::with::h654d467430281288
  22:   0x953c38 - tokio_core::reactor::Core::poll::hfd8ca804eabf02a7
  23:   0x53dc48 - tokio_core::reactor::Core::run::ha8a4a8d15df4a05f
  24:   0x54bb44 - librespot::main::h17b86eb414fa277e
  25:   0x5263dc - std::rt::lang_start::{{closure}}::he764af215f6d223f
  26:   0xa36568 - std::rt::lang_start_internal::{{closure}}::hfac715f2e0a14136
                       at src/libstd/rt.rs:49
  27:   0xa36568 - std::panicking::try::do_call::h5bd3d572724ac2e1
                       at src/libstd/panicking.rs:296
  28:   0xa3db18 - __rust_maybe_catch_panic
                       at src/libpanic_unwind/lib.rs:82
  29:   0xa36fd0 - std::panicking::try::h3203ccbd3c7c13af
                       at src/libstd/panicking.rs:275
  30:   0xa36fd0 - std::panic::catch_unwind::hd9cff17009151b9a

So it seems there is some kind of lockup.

It seems librespot has stopped reading from the mdns socket:

pi@DiningRoom:~ $ sudo netstat -lnp4|grep librespot
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 0.0.0.0:36127 0.0.0.0:* LISTEN 4233/librespot
udp 142144 0 0.0.0.0:5353 0.0.0.0:* 4233/librespot

gdb suggests that all threads are locked up:

[New LWP 4237]
[New LWP 5707]

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".
0x76c33464 in pthread_join (threadid=, thread_return=0x0) at pthread_join.c:90
90 pthread_join.c: No such file or directory.
(gdb)
(gdb) bt
#0 0x76c33464 in pthread_join (threadid=, thread_return=0x0) at pthread_join.c:90
#1 0x00a3d030 in std::sys::unix:🧵:Thread::join::h98dd53d2904cc322 () at src/libstd/sys/unix/thread.rs:165
#2 0x005da538 in std:🧵:JoinHandle$LT$T$GT$::join::h0853f4a1e7365593 ()
#3 0x005d5ac0 in _$LT$librespot_playback..player..Player$u20$as$u20$core..ops..drop..Drop$GT$::drop::h8b117a771a89b4b4 ()
#4 0x0053e78c in core::ptr::real_drop_in_place::h1186091d46e6fc50 ()
#5 0x0054e2b4 in core::ptr::real_drop_in_place::h81963297eb6d1e60 ()
#6 0x0054fa88 in _$LT$tokio_current_thread..scheduler..Scheduler$LT$U$GT$$u20$as$u20$core..ops..drop..Drop$GT$::drop::h58f9143f85f1f7fd ()
#7 0x00546c4c in core::ptr::real_drop_in_place::hc143416570f48b51 ()
#8 0x00544938 in core::ptr::real_drop_in_place::h32239ca035a0d27e ()
#9 0x0054c87c in librespot::main::h17b86eb414fa277e ()
#10 0x7e6ca000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

(gdb) thread 2
[Switching to thread 2 (Thread 0x76b7e120 (LWP 4237))]
#0 0x76e3d704 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
84 ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) bt
#0 0x76e3d704 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1 0x00999e98 in mio::sys::unix::epoll::Selector::select::h0a54d4dfa45e8290 ()
#2 0x00995c1c in mio::poll::Poll::poll1::hd301b86e747a2f5c ()
#3 0x0099573c in mio::poll::Poll::poll::h4fcbf39efec82893 ()
#4 0x0096f090 in tokio_reactor::Reactor::turn::h20570c2a4f4cd7f5 ()
#5 0x00976370 in tokio_reactor::background::run::hb60424d1fa1ebe61 ()
#6 0x009773d4 in std::sys_common::backtrace::__rust_begin_short_backtrace::hd90d34c7b227e928 ()
#7 0x0097742c in std::panicking::try::do_call::h311e790d422b1035 ()
#8 0x00a3db18 in __rust_maybe_catch_panic () at src/libpanic_unwind/lib.rs:82
#9 0x00972acc in core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$u7d::h752fe7814e947266 ()
#10 0x00a275ec in _$LT$alloc..boxed..Box$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$A$GT$GT::call_once::h7221d3aa987d9f9f ()
at /rustc/cd2cd4c9627e52c33e68e8c93a8916dc11094cbb/src/liballoc/boxed.rs:766
#11 0x00a3cf58 in _$LT$alloc..boxed..Box$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$A$GT$GT::call_once::hac0611ced21f0fdb ()
at /rustc/cd2cd4c9627e52c33e68e8c93a8916dc11094cbb/src/liballoc/boxed.rs:766
#12 std::sys_common:🧵:start_thread::h0b76a8eba260b4de () at src/libstd/sys_common/thread.rs:13
#13 std::sys::unix:🧵:Thread:🆕:thread_start::h00b237f6f0bbec97 () at src/libstd/sys/unix/thread.rs:79
#14 0x76c31fc4 in start_thread (arg=0x76b7e120) at pthread_create.c:458
#15 0x76e3d038 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:76 from /lib/arm-linux-gnueabihf/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

(gdb) thread 3
[Switching to thread 3 (Thread 0x757fe120 (LWP 5707))]
#0 0x76c389a4 in __pthread_cond_wait (cond=0x75901140, mutex=0x75900730) at pthread_cond_wait.c:188
188 pthread_cond_wait.c: No such file or directory.
(gdb) bt
#0 0x76c389a4 in __pthread_cond_wait (cond=0x75901140, mutex=0x75900730) at pthread_cond_wait.c:188
#1 0x00636620 in _$LT$librespot_audio..fetch..AudioFileStreaming$u20$as$u20$std..io..Read$GT$::read::h35f2b025181efe57 ()
#2 0x00636950 in _$LT$librespot_audio..fetch..AudioFile$u20$as$u20$std..io..Read$GT$::read::h29fbd4695955c27b ()
#3 0x005fee80 in ogg::reading::UntilPageHeaderReader::do_read::hc87bdd9d28e10f3e ()
#4 0x005fe5bc in ogg::reading::PacketReader$LT$T$GT$::read_ogg_page::h2551059ca789be2a ()
#5 0x005fdb14 in ogg::reading::PacketReader$LT$T$GT$::seek_absgp::he106f00f34297b4e ()
#6 0x005f3798 in lewton::inside_ogg::OggStreamReader$LT$T$GT$::seek_absgp_pg::h918ebdaa8e2ea5cd ()
#7 0x005d7b6c in librespot_playback::player::PlayerInternal::run::h19c92446937f2f52 ()
#8 0x757fcb50 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

(gdb) info threads
Id Target Id Frame

  • 1 Thread 0x76efd000 (LWP 4233) "librespot" 0x76c33464 in pthread_join (threadid=, thread_return=0x0) at pthread_join.c:90
    2 Thread 0x76b7e120 (LWP 4237) "librespot" 0x76e3d704 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
    3 Thread 0x757fe120 (LWP 5707) "librespot" 0x76c389a4 in __pthread_cond_wait (cond=0x75901140, mutex=0x75900730) at pthread_cond_wait.c:188

Letting it run for a minute and breaking again, shows identical stacktraces,
Strace shows no syscalls, apart from a pending futex (IIUC):

strace: Process 4233 attached
futex(0x757fe188, FUTEX_WAIT, 5707, NULLstrace: Process 4233 detached
<detached ...>

I made a core dump file. If it helps, I can share it (but I'm a bit hesitant, since I'm not sure if there's sensitive credentials in there).

Not sure if this is really something that is worth fixing, but I gathered all this debug info before looking at the log and discovering that the cause was out-of-space, and I wanted to share my findings anyway.

Originally created by @matthijskooijman on GitHub (Jul 13, 2019). Original GitHub issue: https://github.com/librespot-org/librespot/issues/349 I had a machine that was running out of diskspace on `/`. This does not seem to be handled gracefully. I found an error message in the logs, but then librespot locks up, no longer responds to mdns queries or, I think, server commands. This was observed with a self-compiled git master version (https://github.com/librespot-org/librespot/commit/4e3576ba7c6146cf68e1953daeec929d619b26b1) Here's the error from the log: ``` [2019-07-13T02:14:19Z INFO librespot_playback::player] Track "Strobelite (feat. Peven Everett)" loaded thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 28, kind: Other, message: "No space left on device" }', src/libcore/result.r stack backtrace: 0: 0xa3637c - backtrace::backtrace::libunwind::trace::hb317fd79f338e9ac at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.29/src/backtrace/libunwind.rs:88 1: 0xa3637c - backtrace::backtrace::trace_unsynchronized::h577e08d87958ca80 at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.29/src/backtrace/mod.rs:66 2: 0xa3637c - std::sys_common::backtrace::_print::hbfee0f6c5053d54e at src/libstd/sys_common/backtrace.rs:47 3: 0xa3637c - std::sys_common::backtrace::print::he0aac2b05fe6a451 at src/libstd/sys_common/backtrace.rs:36 4: 0xa3637c - std::panicking::default_hook::{{closure}}::ha2ef00deb6db7a83 at src/libstd/panicking.rs:200 5: 0xa35f2c - std::panicking::default_hook::h641d7e1cec244c78 at src/libstd/panicking.rs:214 6: 0xa36b40 - std::panicking::rust_panic_with_hook::h4043fa8d29430a82 at src/libstd/panicking.rs:477 7: 0xa36704 - std::panicking::continue_panic_fmt::h69e00c7989848347 at src/libstd/panicking.rs:384 8: 0xa365f0 - rust_begin_unwind at src/libstd/panicking.rs:311 9: 0xa52adc - core::panicking::panic_fmt::h368b1e08709edc0e at src/libcore/panicking.rs:85 10: 0x6815e0 - core::result::unwrap_failed::hb36bb57d205feb44 11: 0x6df6b8 - librespot_core::cache::Cache::save_file::h4840fbb770c45ce6 12: 0x63728c - <futures::future::map::Map<A,F> as futures::future::Future>::poll::hbf2021502e8fa11b 13: 0x6389cc - futures::future::chain::Chain<A,B,C>::poll::hf56c814a8a30a28e 14: 0x94eb70 - futures::task_impl::std::set::h0f3a1953102917fd 15: 0x95b904 - tokio_current_thread::CurrentRunner::set_spawn::hd28e949e3e27e754 16: 0x955138 - tokio_current_thread::scheduler::Scheduler<U>::tick::h3c9a2fb62e4aa42a 17: 0x95bbf0 - tokio_current_thread::Entered<P>::turn::h54e4b6ec1a6350ff 18: 0x94a1fc - scoped_tls::ScopedKey<T>::set::h027fa554916dcb6c 19: 0x954834 - std::thread::local::LocalKey<T>::with::ha544fc008d9bb431 20: 0x954be8 - std::thread::local::LocalKey<T>::with::hec21127b56529e20 21: 0x954398 - std::thread::local::LocalKey<T>::with::h654d467430281288 22: 0x953c38 - tokio_core::reactor::Core::poll::hfd8ca804eabf02a7 23: 0x53dc48 - tokio_core::reactor::Core::run::ha8a4a8d15df4a05f 24: 0x54bb44 - librespot::main::h17b86eb414fa277e 25: 0x5263dc - std::rt::lang_start::{{closure}}::he764af215f6d223f 26: 0xa36568 - std::rt::lang_start_internal::{{closure}}::hfac715f2e0a14136 at src/libstd/rt.rs:49 27: 0xa36568 - std::panicking::try::do_call::h5bd3d572724ac2e1 at src/libstd/panicking.rs:296 28: 0xa3db18 - __rust_maybe_catch_panic at src/libpanic_unwind/lib.rs:82 29: 0xa36fd0 - std::panicking::try::h3203ccbd3c7c13af at src/libstd/panicking.rs:275 30: 0xa36fd0 - std::panic::catch_unwind::hd9cff17009151b9a ``` So it seems there is some kind of lockup. It seems librespot has stopped reading from the mdns socket: pi@DiningRoom:~ $ sudo netstat -lnp4|grep librespot Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp 0 0 0.0.0.0:36127 0.0.0.0:* LISTEN 4233/librespot udp 142144 0 0.0.0.0:5353 0.0.0.0:* 4233/librespot gdb suggests that all threads are locked up: [New LWP 4237] [New LWP 5707] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1". 0x76c33464 in pthread_join (threadid=<optimized out>, thread_return=0x0) at pthread_join.c:90 90 pthread_join.c: No such file or directory. (gdb) (gdb) bt #0 0x76c33464 in pthread_join (threadid=<optimized out>, thread_return=0x0) at pthread_join.c:90 #1 0x00a3d030 in std::sys::unix::thread::Thread::join::h98dd53d2904cc322 () at src/libstd/sys/unix/thread.rs:165 #2 0x005da538 in std::thread::JoinHandle$LT$T$GT$::join::h0853f4a1e7365593 () #3 0x005d5ac0 in _$LT$librespot_playback..player..Player$u20$as$u20$core..ops..drop..Drop$GT$::drop::h8b117a771a89b4b4 () #4 0x0053e78c in core::ptr::real_drop_in_place::h1186091d46e6fc50 () #5 0x0054e2b4 in core::ptr::real_drop_in_place::h81963297eb6d1e60 () #6 0x0054fa88 in _$LT$tokio_current_thread..scheduler..Scheduler$LT$U$GT$$u20$as$u20$core..ops..drop..Drop$GT$::drop::h58f9143f85f1f7fd () #7 0x00546c4c in core::ptr::real_drop_in_place::hc143416570f48b51 () #8 0x00544938 in core::ptr::real_drop_in_place::h32239ca035a0d27e () #9 0x0054c87c in librespot::main::h17b86eb414fa277e () #10 0x7e6ca000 in ?? () Backtrace stopped: previous frame identical to this frame (corrupt stack?) (gdb) thread 2 [Switching to thread 2 (Thread 0x76b7e120 (LWP 4237))] #0 0x76e3d704 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84 84 ../sysdeps/unix/syscall-template.S: No such file or directory. (gdb) bt #0 0x76e3d704 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84 #1 0x00999e98 in mio::sys::unix::epoll::Selector::select::h0a54d4dfa45e8290 () #2 0x00995c1c in mio::poll::Poll::poll1::hd301b86e747a2f5c () #3 0x0099573c in mio::poll::Poll::poll::h4fcbf39efec82893 () #4 0x0096f090 in tokio_reactor::Reactor::turn::h20570c2a4f4cd7f5 () #5 0x00976370 in tokio_reactor::background::run::hb60424d1fa1ebe61 () #6 0x009773d4 in std::sys_common::backtrace::__rust_begin_short_backtrace::hd90d34c7b227e928 () #7 0x0097742c in std::panicking::try::do_call::h311e790d422b1035 () #8 0x00a3db18 in __rust_maybe_catch_panic () at src/libpanic_unwind/lib.rs:82 #9 0x00972acc in core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::h752fe7814e947266 () #10 0x00a275ec in _$LT$alloc..boxed..Box$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$A$GT$$GT$::call_once::h7221d3aa987d9f9f () at /rustc/cd2cd4c9627e52c33e68e8c93a8916dc11094cbb/src/liballoc/boxed.rs:766 #11 0x00a3cf58 in _$LT$alloc..boxed..Box$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$A$GT$$GT$::call_once::hac0611ced21f0fdb () at /rustc/cd2cd4c9627e52c33e68e8c93a8916dc11094cbb/src/liballoc/boxed.rs:766 #12 std::sys_common::thread::start_thread::h0b76a8eba260b4de () at src/libstd/sys_common/thread.rs:13 #13 std::sys::unix::thread::Thread::new::thread_start::h00b237f6f0bbec97 () at src/libstd/sys/unix/thread.rs:79 #14 0x76c31fc4 in start_thread (arg=0x76b7e120) at pthread_create.c:458 #15 0x76e3d038 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:76 from /lib/arm-linux-gnueabihf/libc.so.6 Backtrace stopped: previous frame identical to this frame (corrupt stack?) (gdb) thread 3 [Switching to thread 3 (Thread 0x757fe120 (LWP 5707))] #0 0x76c389a4 in __pthread_cond_wait (cond=0x75901140, mutex=0x75900730) at pthread_cond_wait.c:188 188 pthread_cond_wait.c: No such file or directory. (gdb) bt #0 0x76c389a4 in __pthread_cond_wait (cond=0x75901140, mutex=0x75900730) at pthread_cond_wait.c:188 #1 0x00636620 in _$LT$librespot_audio..fetch..AudioFileStreaming$u20$as$u20$std..io..Read$GT$::read::h35f2b025181efe57 () #2 0x00636950 in _$LT$librespot_audio..fetch..AudioFile$u20$as$u20$std..io..Read$GT$::read::h29fbd4695955c27b () #3 0x005fee80 in ogg::reading::UntilPageHeaderReader::do_read::hc87bdd9d28e10f3e () #4 0x005fe5bc in ogg::reading::PacketReader$LT$T$GT$::read_ogg_page::h2551059ca789be2a () #5 0x005fdb14 in ogg::reading::PacketReader$LT$T$GT$::seek_absgp::he106f00f34297b4e () #6 0x005f3798 in lewton::inside_ogg::OggStreamReader$LT$T$GT$::seek_absgp_pg::h918ebdaa8e2ea5cd () #7 0x005d7b6c in librespot_playback::player::PlayerInternal::run::h19c92446937f2f52 () #8 0x757fcb50 in ?? () Backtrace stopped: previous frame identical to this frame (corrupt stack?) (gdb) info threads Id Target Id Frame * 1 Thread 0x76efd000 (LWP 4233) "librespot" 0x76c33464 in pthread_join (threadid=<optimized out>, thread_return=0x0) at pthread_join.c:90 2 Thread 0x76b7e120 (LWP 4237) "librespot" 0x76e3d704 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84 3 Thread 0x757fe120 (LWP 5707) "librespot" 0x76c389a4 in __pthread_cond_wait (cond=0x75901140, mutex=0x75900730) at pthread_cond_wait.c:188 Letting it run for a minute and breaking again, shows identical stacktraces, Strace shows no syscalls, apart from a pending futex (IIUC): strace: Process 4233 attached futex(0x757fe188, FUTEX_WAIT, 5707, NULLstrace: Process 4233 detached <detached ...> I made a core dump file. If it helps, I can share it (but I'm a bit hesitant, since I'm not sure if there's sensitive credentials in there). Not sure if this is really something that is worth fixing, but I gathered all this debug info before looking at the log and discovering that the cause was out-of-space, and I wanted to share my findings anyway.
kerem closed this issue 2026-02-27 19:29:32 +03:00
Author
Owner

@sashahilton00 commented on GitHub (Jan 31, 2021):

Resolved in #518

<!-- gh-comment-id:770314823 --> @sashahilton00 commented on GitHub (Jan 31, 2021): Resolved in #518
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/librespot#229
No description provided.