03-26-2021, 07:57 PM
Hi,
i'm using rasbperry 4 running moode 7.1 connected via USB cable Cambridge audio CXA81 amplifier with build in DAC.
Everything works very well with one exception, when I'm powering off amplifier while playing music from spotify, librespot crashes
In order to debug it, I've started proces in verbose mode running following command
when I start playing music and power off amplifier, following error log appear in the console
but process still works until I will disconnect spotify on my computer/mobile, once I change output to local machine following log appear in the console
How i can fix this issue? I was thinking about detecting that librespot process is down and restarting it but it doesn't die until i disconnect so it would be still semi automatic solution.
any ideas?
Many thanks for help
i'm using rasbperry 4 running moode 7.1 connected via USB cable Cambridge audio CXA81 amplifier with build in DAC.
Everything works very well with one exception, when I'm powering off amplifier while playing music from spotify, librespot crashes
In order to debug it, I've started proces in verbose mode running following command
Code:
sudo librespot --name CambridgeAudio --bitrate 320 --initial-volume 100 --volume-ctrl linear --autoplay --cache /var/local/www/spotify_cache --disable-audio-cache --backend alsa --device alsaequal --verbose --onevent /var/local/www/commandw/spotevent.shwhen I start playing music and power off amplifier, following error log appear in the console
Code:
ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred
ALSA lib pcm.c:8427:(snd_pcm_recover) cannot recovery from underrun, prepare failed: File descriptor in bad state
thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: Error("snd_pcm_recover", Sys(EBADFD))', playback/src/audio_backend/alsa.rs:142:61
stack backtrace:
0: 0x8c6e00 - std::backtrace_rs::backtrace::libunwind::trace::h03f08998830b327f
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
1: 0x8c6e00 - std::backtrace_rs::backtrace::trace_unsynchronized::hc904ce59e3b3ddf8
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2: 0x8c6e00 - std::sys_common::backtrace::_print_fmt::hc6ca3e88c9c15384
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:67:5
3: 0x8c6e00 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h96b70ae78df0c6ff
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:46:22
4: 0x8f142c - core::fmt::write::hd1e952447dcf60ff
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/fmt/mod.rs:1078:17
5: 0x8be990 - std::io::Write::write_fmt::h9c9e73249660260e
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/io/mod.rs:1517:15
6: 0x8c9628 - std::sys_common::backtrace::_print::h48c27a23da6d8107
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:49:5
7: 0x8c9628 - std::sys_common::backtrace::print::hcb4061a9ac940b04
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:36:9
8: 0x8c9628 - std::panicking::default_hook::{{closure}}::h68ceed982cb697a5
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:208:50
9: 0x8c9054 - std::panicking::default_hook::h90748cf9ce43cfc9
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:225:9
10: 0x8c9e3c - std::panicking::rust_panic_with_hook::hbddc3a086ec95248
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:591:17
11: 0x8c999c - std::panicking::begin_panic_handler::{{closure}}::h83ccc4302bb49358
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:497:13
12: 0x8c737c - std::sys_common::backtrace::__rust_end_short_backtrace::h3142e1e09cb0c983
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:141:18
13: 0x8c98e4 - rust_begin_unwind
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:493:5
14: 0x8ede5c - core::panicking::panic_fmt::he396093a5f6f49ce
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/panicking.rs:92:14
15: 0x8edcb4 - core::option::expect_none_failed::h63bf2dccfc18387b
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/option.rs:1268:5
16: 0x5c2ec4 - <librespot_playback::audio_backend::alsa::AlsaSink as librespot_playback::audio_backend::Sink>::write::h0b69d1ceededa1cd
17: 0x5cef70 - <librespot_playback::player::PlayerInternal as futures::future::Future>::poll::h79a44c57fca0690c
18: 0x518750 - std::sys_common::backtrace::__rust_begin_short_backtrace::hab0b5ae799b3819b
19: 0x519950 - core::ops::function::FnOnce::call_once{{vtable.shim}}::hab1cf2ea4398dc70
20: 0x8d04e0 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h39ca8f5e1255e35d
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/alloc/src/boxed.rs:1328:9
21: 0x8d04e0 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h032a878b93a7e697
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/alloc/src/boxed.rs:1328:9
22: 0x8d04e0 - std::sys::unix::thread::Thread::new::thread_start::he7a0e9f89a4fa658
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys/unix/thread.rs:71:17
[2021-03-26T19:39:39Z DEBUG librespot_playback::player] drop PlayerInternal[0]
[2021-03-26T19:41:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4
[2021-03-26T19:43:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4
[2021-03-26T19:45:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4
[2021-03-26T19:47:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4
[2021-03-26T19:49:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4
[2021-03-26T19:51:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4
[2021-03-26T19:53:20Z DEBUG librespot_core::session] Session[0] strong=2 weak=4but process still works until I will disconnect spotify on my computer/mobile, once I change output to local machine following log appear in the console
Code:
[2021-03-26T19:54:28Z DEBUG librespot_connect::spirc] kMessageTypeNotify "MacBook Pro" f0d5f004f8f7bfb770802c26de3ddfd012edde44 1880765975 1616788468519 kPlayStatusStop
[2021-03-26T19:54:29Z DEBUG librespot_connect::spirc] kMessageTypeNotify "MacBook Pro" f0d5f004f8f7bfb770802c26de3ddfd012edde44 1880767268 1616788469812 kPlayStatusPlay
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SendError("...")', playback/src/player.rs:277:61
stack backtrace:
0: 0x8c6e00 - std::backtrace_rs::backtrace::libunwind::trace::h03f08998830b327f
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
1: 0x8c6e00 - std::backtrace_rs::backtrace::trace_unsynchronized::hc904ce59e3b3ddf8
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2: 0x8c6e00 - std::sys_common::backtrace::_print_fmt::hc6ca3e88c9c15384
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:67:5
3: 0x8c6e00 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h96b70ae78df0c6ff
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:46:22
4: 0x8f142c - core::fmt::write::hd1e952447dcf60ff
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/fmt/mod.rs:1078:17
5: 0x8be990 - std::io::Write::write_fmt::h9c9e73249660260e
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/io/mod.rs:1517:15
6: 0x8c9628 - std::sys_common::backtrace::_print::h48c27a23da6d8107
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:49:5
7: 0x8c9628 - std::sys_common::backtrace::print::hcb4061a9ac940b04
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:36:9
8: 0x8c9628 - std::panicking::default_hook::{{closure}}::h68ceed982cb697a5
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:208:50
9: 0x8c9054 - std::panicking::default_hook::h90748cf9ce43cfc9
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:225:9
10: 0x8c9e3c - std::panicking::rust_panic_with_hook::hbddc3a086ec95248
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:591:17
11: 0x8c999c - std::panicking::begin_panic_handler::{{closure}}::h83ccc4302bb49358
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:497:13
12: 0x8c737c - std::sys_common::backtrace::__rust_end_short_backtrace::h3142e1e09cb0c983
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:141:18
13: 0x8c98e4 - rust_begin_unwind
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:493:5
14: 0x8ede5c - core::panicking::panic_fmt::he396093a5f6f49ce
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/panicking.rs:92:14
15: 0x8edcb4 - core::option::expect_none_failed::h63bf2dccfc18387b
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/option.rs:1268:5
16: 0x5c77b8 - librespot_playback::player::Player::command::h6247f2019150bef4
17: 0x5c791c - librespot_playback::player::Player::stop::hd8b17c78a3f01aaa
18: 0x59bf28 - <librespot_connect::spirc::SpircTask as futures::future::Future>::poll::hbfbb6ab224368cff
19: 0x539e28 - <librespot::Main as futures::future::Future>::poll::h496b11a2e55c6fcf
20: 0x52f934 - futures::task_impl::Spawn<T>::enter::{{closure}}::hfa91044fa2763699
21: 0x53cec0 - librespot::main::h9ca5fc77fed0670f
22: 0x518198 - std::sys_common::backtrace::__rust_begin_short_backtrace::h999d5981e7f994c3
23: 0x518fbc - std::rt::lang_start::{{closure}}::h6cb924fff4c08117
24: 0x8ca25c - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h221669f198ddd75e
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/ops/function.rs:259:13
25: 0x8ca25c - std::panicking::try::do_call::h2f523e82afd7b171
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:379:40
26: 0x8ca25c - std::panicking::try::h23f86446f10cedcb
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:343:19
27: 0x8ca25c - std::panic::catch_unwind::hd9d2d31af6b8e2f8
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panic.rs:396:14
28: 0x8ca25c - std::rt::lang_start_internal::h2070b43e8853ebbe
at /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/rt.rs:51:25
29: 0x53ed00 - main
30: 0xb6c3d718 - __libc_start_main
[2021-03-26T19:54:29Z DEBUG librespot_connect::spirc] drop Spirc[0]
[2021-03-26T19:54:29Z DEBUG librespot_playback::player] Shutting down player thread ...
[2021-03-26T19:54:29Z ERROR librespot_playback::player] Player thread panicked!
[2021-03-26T19:54:29Z DEBUG librespot_core::session] drop Session[0]
[2021-03-26T19:54:29Z DEBUG librespot_core::audio_key] drop AudioKeyManager
[2021-03-26T19:54:29Z DEBUG librespot_core::channel] drop ChannelManager
[2021-03-26T19:54:29Z DEBUG librespot_core::mercury] drop MercuryManager
[2021-03-26T19:54:29Z DEBUG librespot_core::session] drop DispatchHow i can fix this issue? I was thinking about detecting that librespot process is down and restarting it but it doesn't die until i disconnect so it would be still semi automatic solution.
any ideas?
Many thanks for help
