Spotify Connect for Volumio 3 randomly stops playing after a few mins

Plugins
1

Using Volumio 3.198, when using the Spotify Connect plugin, it will randomly cut out after a few mins, and I have to then restart playing from my Android phone.

I checked the logs and got this:

Blockquote
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
[Vollibrespot] : Loading with Spotify URI
[Vollibrespot] : (449887 ms) loaded
[Vollibrespot] : Event: Next { track_id: SpotifyId { id: 15852934216298068530934639522083754577, audio_type: Track } }
[Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 69115100874654805158485565349094005223, audio_type: Track }, track_id: SpotifyId { id: 15852934216298068530934639522083754577, audio_type: Track } }
[SpotifyConnect] Blue Crystal Fire
[SpotifyConnect] Pushing metadata
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred
ALSA lib pcm.c:8427:(snd_pcm_recover) cannot recovery from underrun, prepare failed: Device or resource busy
thread ‘’ panicked at ‘called Result::unwrap() on an Err value: Error(“snd_pcm_recover”, Sys(EBUSY))’, /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/playback/src/audio_backend/alsa.rs:134:53
stack backtrace:
0: 0xa2d040 - std::backtrace_rs::backtrace::libunwind::trace::h4e6fc6cdc5d76862
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/…/…/backtrace/src/backtrace/libunwind.rs:90:5
1: 0xa2d040 - std::backtrace_rs::backtrace::trace_unsynchronized::h1c665adaaf480d86
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/…/…/backtrace/src/backtrace/mod.rs:66:5
2: 0xa2d040 - std::sys_common::backtrace::_print_fmt::h39ff02745027e048
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:67:5
3: 0xa2d040 - ::fmt::hc83ae421f857c6ae
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:46:22
4: 0xa4e6a4 - core::fmt::write::h59f33d28fc1a9cf5
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/fmt/mod.rs:1092:17
5: 0xa25fec - std::io::Write::write_fmt::h96774110acd52d88
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/io/mod.rs:1572:15
6: 0xa2f74c - std::sys_common::backtrace::_print::h28b9431057012c44
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:49:5
7: 0xa2f74c - std::sys_common::backtrace::print::h28173b7ebfe4a4ac
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:36:9
8: 0xa2f74c - std::panicking::default_hook::{{closure}}::h12f82aa3def34336
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:208:50
9: 0xa2f12c - std::panicking::default_hook::hee29440c29c1cc2e
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:225:9
10: 0xa2fdac - std::panicking::rust_panic_with_hook::he7d3b6e3eee77e72
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:591:17
11: 0xa2f928 - std::panicking::begin_panic_handler::{{closure}}::h7faba6b3632756a6
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:497:13
12: 0xa2d5bc - std::sys_common::backtrace::__rust_end_short_backtrace::hdde0f982a7a71ce9
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:141:18
13: 0xa2f870 - rust_begin_unwind
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:493:5
14: 0x50921c - core::panicking::panic_fmt::h97b6949f75a63095
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:92:14
15: 0x509120 - core::option::expect_none_failed::h4525992415ba2383
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/option.rs:1329:5
16: 0x643c24 - ::write::h2dc31352d1009910
17: 0x626588 - ::poll::h8080398afd4135f1
18: 0x5493ac - futures::task_impl::std::set::h5f18eafe66b6e0ce
19: 0x535c88 - futures::task_impl::Spawn::poll_future_notify::hb5fbdb91a4afa239
20: 0x55aad0 - futures::future::Future::wait::h720e8c679b25c377
21: 0x562330 - std::sys_common::backtrace::__rust_begin_short_backtrace::h71e7578ce733f5f0
22: 0x555004 - core::ops::function::FnOnce::call_once{{vtable.shim}}::hf986f3b67bd2f3cd
23: 0xa33430 - as core::ops::function::FnOnce>::call_once::h55699fe2dcd01fb2
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/alloc/src/boxed.rs:1546:9
24: 0xa33430 - as core::ops::function::FnOnce>::call_once::h767211a722faedbf
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/alloc/src/boxed.rs:1546:9
25: 0xa33430 - std::sys::unix:: thread:: Thread:: new::thread_start::h4c3152afb00cbdcf
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys/unix/thread.rs:71:17

Any thoughts on what’s going on here?

2

What device is this? Perhaps share some full logs? You have underruns, and the daemon isn’t able to feed the alsa sink fast enough…

3

It’s a Raspberry Pi 4 Model B, Rev 1.4 with 4GB RAM.

Can you point me to where I can find the full logs?

4

https://volumio.github.io/docs/User_Manual/Sending_logs_for_troubleshooting.html

5

http://logs.volumio.org/volumio/8u9jV5J.html

6

Why do you have so many mpd connections? Please try disabling the mpd_oled plugin.

Also the wall of getState suggests something is polling your device, and the poor thing is getting overloaded. Figure that out, and the tunes should flow…

7

Ok, so it looks like MPD_OLED is causing all the getState commands. When I disable MPD_OLED those commands stop, and Spotify Connect doesn’t abruptly stop playing after a few mins (just tested listening for ~15 mins and no issues).

So now I need to figure out why MPD_OLED keeps sending those getState commands. Will continue in the MPD_OLED thread.