search

dtcooper / raspotify

A Spotify Connect client that mostly Just Works™
https://dtcooper.github.io/raspotify
MIT License
4.65k stars 217 forks source link

Loop & delay when playing a song #351

Closed PaulMatthieu closed 3 years ago

PaulMatthieu commented 3 years ago

I was using raspotify to stream music to a raspberry pi 4. My raspberry is connected (and outputs sounds) to a DAC but I don't think the issue comes from the DAC as it used to work before and still works Since I've upgraded from 0.14.0~librespot.20200724T030042Z.6aac8a6 to 0.16.0~librespot.v0.1.3-37-g0adb851, it's no longer working: I hear loops of the song and there is a delay when playing/pausing songs. Changing from a song to another seem to crash raspotify/librespot.

Backtrace example:


Jan 10 20:01:04 musicbox librespot[6945]: [2021-01-10T20:01:04Z INFO  librespot_core::session] Country: "FR"
Jan 10 20:02:43 musicbox librespot[6945]: [2021-01-10T20:02:43Z INFO  librespot_playback::player] Loading <Shadows From Nowhere - Original Version> with Spotify URI <spotify:track:7kF2wPFh949jhWzeTyODnO>
Jan 10 20:02:43 musicbox librespot[6945]: [2021-01-10T20:02:43Z INFO  librespot_playback::player] <Shadows From Nowhere - Original Version> (330310 ms) loaded
Jan 10 20:04:01 musicbox librespot[6945]: thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: Error("snd_pcm_drain", Sys(EIO))', playback/src/audio_backend/alsa.rs:121:25
Jan 10 20:04:01 musicbox librespot[6945]: stack backtrace:
Jan 10 20:04:01 musicbox librespot[6945]:    0:   0x917278 - std::backtrace_rs::backtrace::libunwind::trace::h9c6af82ecb947420
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/libunwind.rs:96
Jan 10 20:04:01 musicbox librespot[6945]:    1:   0x917278 - std::backtrace_rs::backtrace::trace_unsynchronized::h80561bf66e637b12
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/mod.rs:66
Jan 10 20:04:01 musicbox librespot[6945]:    2:   0x917278 - std::sys_common::backtrace::_print_fmt::h8904fddc87bf6b5e
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:79
Jan 10 20:04:01 musicbox librespot[6945]:    3:   0x917278 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hc883ceb7a13219f2
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:58
Jan 10 20:04:01 musicbox librespot[6945]:    4:   0x93f290 - core::fmt::write::ha75209c8e86bef45
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/fmt/mod.rs:1080
Jan 10 20:04:01 musicbox librespot[6945]:    5:   0x90fe18 - std::io::Write::write_fmt::h4cce8be81a41c537
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/io/mod.rs:1516
Jan 10 20:04:01 musicbox librespot[6945]:    6:   0x91a1c0 - std::sys_common::backtrace::_print::hdc9e28891c09ab0b
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:61
Jan 10 20:04:01 musicbox librespot[6945]:    7:   0x91a1c0 - std::sys_common::backtrace::print::h85895381379b4dc1
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:48
Jan 10 20:04:01 musicbox librespot[6945]:    8:   0x91a1c0 - std::panicking::default_hook::{{closure}}::h6b4de484f2428118
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:208
Jan 10 20:04:01 musicbox librespot[6945]:    9:   0x919dbc - std::panicking::default_hook::h3966366a200b03f1
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:227
Jan 10 20:04:01 musicbox librespot[6945]:   10:   0x91a910 - std::panicking::rust_panic_with_hook::h068b5368b0949ced
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:577
Jan 10 20:04:01 musicbox librespot[6945]:   11:   0x91a4c4 - std::panicking::begin_panic_handler::{{closure}}::hde463ebfc6f96538
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:484
Jan 10 20:04:01 musicbox librespot[6945]:   12:   0x9177f8 - std::sys_common::backtrace::__rust_end_short_backtrace::hb945924c40726c97
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153
Jan 10 20:04:01 musicbox librespot[6945]:   13:   0x91a47c - rust_begin_unwind
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:483
Jan 10 20:04:01 musicbox librespot[6945]:   14:   0x93c960 - core::panicking::panic_fmt::h27b19d6e6dedd33e
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/panicking.rs:85
Jan 10 20:04:01 musicbox librespot[6945]:   15:   0x93c7b8 - core::option::expect_none_failed::h0ec77a052e666b69
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/option.rs:1234
Jan 10 20:04:01 musicbox librespot[6945]:   16:   0x5a2d84 - <librespot_playback::audio_backend::alsa::AlsaSink as librespot_playback::audio_backend::Sink>::stop::h597a551598048042
Jan 10 20:04:01 musicbox librespot[6945]:   17:   0x583a8c - librespot_playback::player::PlayerInternal::ensure_sink_stopped::ha93e345c49c14f49
Jan 10 20:04:01 musicbox librespot[6945]:   18:   0x580ee4 - <librespot_playback::player::PlayerInternal as futures::future::Future>::poll::he6e04a5bccf94e34
Jan 10 20:04:01 musicbox librespot[6945]:   19:   0x4e4300 - futures::task_impl::std::set::hab1c1811473e3998
Jan 10 20:04:01 musicbox librespot[6945]:   20:   0x4da838 - std::sys_common::backtrace::__rust_begin_short_backtrace::h8286c5a0fd04a387
Jan 10 20:04:01 musicbox librespot[6945]:   21:   0x4f54f4 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h76e6c7604d7daced
Jan 10 20:04:01 musicbox librespot[6945]:   22:   0x921940 - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h6b7ad05f87ff90ae
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/alloc/src/boxed.rs:1042
Jan 10 20:04:01 musicbox librespot[6945]:   23:   0x921940 - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::he9130e675b8d97ee
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/alloc/src/boxed.rs:1042
Jan 10 20:04:01 musicbox librespot[6945]:   24:   0x921940 - std::sys::unix::thread::Thread::new::thread_start::h7a3f6590d8e03e95
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys/unix/thread.rs:87
Jan 10 20:04:01 musicbox librespot[6945]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SendError("...")', playback/src/player.rs:281:61
Jan 10 20:04:01 musicbox librespot[6945]: stack backtrace:
Jan 10 20:04:01 musicbox librespot[6945]:    0:   0x917278 - std::backtrace_rs::backtrace::libunwind::trace::h9c6af82ecb947420
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/libunwind.rs:96
Jan 10 20:04:01 musicbox librespot[6945]:    1:   0x917278 - std::backtrace_rs::backtrace::trace_unsynchronized::h80561bf66e637b12
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/mod.rs:66
Jan 10 20:04:01 musicbox librespot[6945]:    2:   0x917278 - std::sys_common::backtrace::_print_fmt::h8904fddc87bf6b5e
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:79
Jan 10 20:04:01 musicbox librespot[6945]:    3:   0x917278 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hc883ceb7a13219f2
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:58
Jan 10 20:04:01 musicbox librespot[6945]:    4:   0x93f290 - core::fmt::write::ha75209c8e86bef45
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/fmt/mod.rs:1080
Jan 10 20:04:01 musicbox librespot[6945]:    5:   0x90fe18 - std::io::Write::write_fmt::h4cce8be81a41c537
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/io/mod.rs:1516
Jan 10 20:04:01 musicbox librespot[6945]:    6:   0x91a1c0 - std::sys_common::backtrace::_print::hdc9e28891c09ab0b
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:61
Jan 10 20:04:01 musicbox librespot[6945]:    7:   0x91a1c0 - std::sys_common::backtrace::print::h85895381379b4dc1
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:48
Jan 10 20:04:01 musicbox librespot[6945]:    8:   0x91a1c0 - std::panicking::default_hook::{{closure}}::h6b4de484f2428118
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:208
Jan 10 20:04:01 musicbox librespot[6945]:    9:   0x919dbc - std::panicking::default_hook::h3966366a200b03f1
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:227
Jan 10 20:04:01 musicbox librespot[6945]:   10:   0x91a910 - std::panicking::rust_panic_with_hook::h068b5368b0949ced
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:577
Jan 10 20:04:01 musicbox librespot[6945]:   11:   0x91a4c4 - std::panicking::begin_panic_handler::{{closure}}::hde463ebfc6f96538
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:484
Jan 10 20:04:01 musicbox librespot[6945]:   12:   0x9177f8 - std::sys_common::backtrace::__rust_end_short_backtrace::hb945924c40726c97
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153
Jan 10 20:04:01 musicbox librespot[6945]:   13:   0x91a47c - rust_begin_unwind
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:483
Jan 10 20:04:01 musicbox librespot[6945]:   14:   0x93c960 - core::panicking::panic_fmt::h27b19d6e6dedd33e
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/panicking.rs:85
Jan 10 20:04:01 musicbox librespot[6945]:   15:   0x93c7b8 - core::option::expect_none_failed::h0ec77a052e666b69
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/option.rs:1234
Jan 10 20:04:01 musicbox librespot[6945]:   16:   0x57cc00 - librespot_playback::player::Player::load::hacb88de657fc208d
Jan 10 20:04:01 musicbox librespot[6945]:   17:   0x52e508 - librespot_connect::spirc::SpircTask::load_track::h8656bac7817c7372
Jan 10 20:04:01 musicbox librespot[6945]:   18:   0x52ac30 - <librespot_connect::spirc::SpircTask as futures::future::Future>::poll::h400d0c6a9af9b895
Jan 10 20:04:01 musicbox librespot[6945]:   19:   0x4f0ab4 - <librespot::Main as futures::future::Future>::poll::h169a5d4027f550f1
Jan 10 20:04:01 musicbox librespot[6945]:   20:   0x4e3cf0 - futures::task_impl::std::set::h171bb0e3315231c5
Jan 10 20:04:01 musicbox librespot[6945]:   21:   0x5025b0 - <futures::future::lazy::Lazy<F,R> as futures::future::Future>::poll::h6ad5d06c62a954b1
Jan 10 20:04:01 musicbox librespot[6945]:   22:   0x4e3e70 - futures::task_impl::std::set::h1b4107da043418f3
Jan 10 20:04:01 musicbox librespot[6945]:   23:   0x4dac1c - std::thread::local::LocalKey<T>::with::h10f666118935c490
Jan 10 20:04:01 musicbox librespot[6945]:   24:   0x4d96b8 - tokio_current_thread::Entered<P>::block_on::hbb47725fa57f8e44
Jan 10 20:04:01 musicbox librespot[6945]:   25:   0x4e05b8 - tokio_timer::timer::handle::with_default::h938751ab893a9316
Jan 10 20:04:01 musicbox librespot[6945]:   26:   0x4daff8 - std::thread::local::LocalKey<T>::with::hed23bc0e3035947a
Jan 10 20:04:01 musicbox librespot[6945]:   27:   0x4d8990 - scoped_tls::ScopedKey<T>::set::heda756cd7e82ddd6
Jan 10 20:04:01 musicbox librespot[6945]:   28:   0x4dfcf0 - tokio_core::reactor::Core::run::hccb77cd75ccb2c67
Jan 10 20:04:01 musicbox librespot[6945]:   29:   0x4f3448 - librespot::main::h6da7c78e457a1f2f
Jan 10 20:04:01 musicbox librespot[6945]:   30:   0x4daabc - std::sys_common::backtrace::__rust_begin_short_backtrace::h92f05e3879870930
Jan 10 20:04:01 musicbox librespot[6945]:   31:   0x4fd30c - std::rt::lang_start::{{closure}}::h067bf4c6ab425fd6
Jan 10 20:04:01 musicbox librespot[6945]:   32:   0x91ad30 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h2c136973bfb85920
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259
Jan 10 20:04:01 musicbox librespot[6945]:   33:   0x91ad30 - std::panicking::try::do_call::hc0787118c306af2e
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381
Jan 10 20:04:01 musicbox librespot[6945]:   34:   0x91ad30 - std::panicking::try::he0aeb9ab5f254114
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345
Jan 10 20:04:01 musicbox librespot[6945]:   35:   0x91ad30 - std::panic::catch_unwind::hb91533e13ff48846
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382
Jan 10 20:04:01 musicbox librespot[6945]:   36:   0x91ad30 - std::rt::lang_start_internal::hf9465186f7b70c75
Jan 10 20:04:01 musicbox librespot[6945]:                        at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51
Jan 10 20:04:01 musicbox librespot[6945]:   37:   0x4f4460 - main
Jan 10 20:04:01 musicbox librespot[6945]:   38: 0xb6c52718 - __libc_start_main
Jan 10 20:04:01 musicbox librespot[6945]: [2021-01-10T20:04:01Z ERROR librespot_playback::player] Player thread panicked!
Jan 10 20:04:01 musicbox systemd[1]: raspotify.service: Main process exited, code=exited, status=101/n/a
Jan 10 20:04:01 musicbox systemd[1]: raspotify.service: Failed with result 'exit-code'.```
thiesschneider commented 3 years ago

how did you solve this?

PaulMatthieu commented 3 years ago

how did you solve this?

I didn't, but I later started experiencing similar issues in other applications (I use VLC to stream radios too), using the IQAudio DAC. So I unplugged the DAC, and raspotify's been working fine since then. I closed the issue because I didn't have time to further investigate it and I'm no longer sure this is a bug specific to raspotify : I suspect there is a problem with alsa and my DAC, but it's a bit outside my area of expertise. I'll let you know if I find anything.