-- Logs begin at Sat 2024-04-06 12:50:06 UTC, end at Sun 2024-04-07 09:20:12 UTC. -- Apr 07 09:19:15 rivo volumio[21925]: [Vollibrespot] : Fetching autoplay context uri Apr 07 09:19:15 rivo volumio[21925]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 119414075360767724878697810268775955797, audio_type: Track }, track_id: SpotifyId { id: 42653428967032860975814884945456040374, audio_type: Track } } Apr 07 09:19:15 rivo volumio[21925]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:0bNkIzGVewls8b0UP1Ki92"> Apr 07 09:19:15 rivo volumio[21925]: [Vollibrespot] : Resolving uri "spotify:station:playlist:0bNkIzGVewls8b0UP1Ki92" Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Loading with Spotify URI Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : (190344 ms) loaded Apr 07 09:19:16 rivo volumio[21925]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed Apr 07 09:19:16 rivo volumio[21925]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed Apr 07 09:19:16 rivo volumio[21925]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed Apr 07 09:19:16 rivo volumio[21925]: thread '' panicked at 'called `Option::unwrap()` on a `None` value', /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/playback/src/audio_backend/alsa.rs:129:35 Apr 07 09:19:16 rivo volumio[21925]: stack backtrace: Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 42653428967032860975814884945456040374, audio_type: Track } } Apr 07 09:19:16 rivo volumio[5339]: [SpotifyConnect] Adicted To You Apr 07 09:19:16 rivo volumio[5339]: [SpotifyConnect] Device palyback is loading Apr 07 09:19:16 rivo volumio[21925]: 0: 0xab6db444 - std::backtrace_rs::backtrace::libunwind::trace::h40a4eff66330a36d Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5 Apr 07 09:19:16 rivo volumio[21925]: 1: 0xab6db444 - std::backtrace_rs::backtrace::trace_unsynchronized::hbce01963451b0cd5 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 Apr 07 09:19:16 rivo volumio[21925]: 2: 0xab6db444 - std::sys_common::backtrace::_print_fmt::h95da650d09c7e00b Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:66:5 Apr 07 09:19:16 rivo volumio[21925]: 3: 0xab6db444 - ::fmt::h33b23b1d14f668ff Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:45:22 Apr 07 09:19:16 rivo volumio[21925]: 4: 0xab7040dc - core::fmt::write::h6320fb0e6ac90e58 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/fmt/mod.rs:1190:17 Apr 07 09:19:16 rivo volumio[21925]: 5: 0xab6d34c4 - std::io::Write::write_fmt::h33b25d4810ca481f Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/io/mod.rs:1657:15 Apr 07 09:19:16 rivo volumio[21925]: 6: 0xab6ddef4 - std::sys_common::backtrace::_print::h7e61c5be69c715ef Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:48:5 Apr 07 09:19:16 rivo volumio[21925]: 7: 0xab6ddef4 - std::sys_common::backtrace::print::h3cee176d7c8dab8b Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:35:9 Apr 07 09:19:16 rivo volumio[21925]: 8: 0xab6ddef4 - std::panicking::default_hook::{{closure}}::h2d0211dd2e97dc43 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:295:22 Apr 07 09:19:16 rivo volumio[21925]: 9: 0xab6ddb14 - std::panicking::default_hook::hcbdb3b7c40dca30c Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:314:9 Apr 07 09:19:16 rivo volumio[21925]: 10: 0xab6de694 - std::panicking::rust_panic_with_hook::h4ce49e7a343dc12b Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:698:17 Apr 07 09:19:16 rivo volumio[21925]: 11: 0xab6de360 - std::panicking::begin_panic_handler::{{closure}}::h4961100fae529fe9 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:586:13 Apr 07 09:19:16 rivo volumio[21925]: 12: 0xab6db9c4 - std::sys_common::backtrace::__rust_end_short_backtrace::hf2e68e62c7a80f1f Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:138:18 Apr 07 09:19:16 rivo volumio[21925]: 13: 0xab6de098 - rust_begin_unwind Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:584:5 Apr 07 09:19:16 rivo volumio[21925]: 14: 0xab1c16f4 - core::panicking::panic_fmt::h84c42730e4a50809 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/panicking.rs:143:14 Apr 07 09:19:16 rivo volumio[21925]: 15: 0xab1c15c8 - core::panicking::panic::h929d4344847bfdba Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/panicking.rs:48:5 Apr 07 09:19:16 rivo volumio[21925]: 16: 0xab2fc158 - ::write::h2857e81996e06a1e Apr 07 09:19:16 rivo volumio[21925]: 17: 0xab2de814 - ::poll::hf6331a81451dbb28 Apr 07 09:19:16 rivo volumio[21925]: 18: 0xab2066c0 - futures::task_impl::std::set::hb731921744f9247e Apr 07 09:19:16 rivo volumio[21925]: 19: 0xab1f7708 - futures::task_impl::Spawn::poll_future_notify::h08f2c87ba9a4eead Apr 07 09:19:16 rivo volumio[21925]: 20: 0xab20b158 - std::sys_common::backtrace::__rust_begin_short_backtrace::hb598e9d2970dbf13 Apr 07 09:19:16 rivo volumio[21925]: 21: 0xab237e70 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h7f140b0cfa5289e1 Apr 07 09:19:16 rivo volumio[21925]: 22: 0xab6e2ebc - as core::ops::function::FnOnce>::call_once::hbc4d03a1815e028a Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/alloc/src/boxed.rs:1853:9 Apr 07 09:19:16 rivo volumio[21925]: 23: 0xab6e2ebc - as core::ops::function::FnOnce>::call_once::h6055603e421418e8 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/alloc/src/boxed.rs:1853:9 Apr 07 09:19:16 rivo volumio[21925]: 24: 0xab6e2ebc - std::sys::unix::thread::Thread::new::thread_start::h0518d9d0e6b0ba31 Apr 07 09:19:16 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys/unix/thread.rs:108:17 Apr 07 09:19:16 rivo volumio[21925]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:0bNkIzGVewls8b0UP1Ki92"> Apr 07 09:19:16 rivo volumio[5339]: info: Is Connect Playback Apr 07 09:19:16 rivo volumio[5339]: info: New connect session, clearing queue Apr 07 09:19:16 rivo volumio[5339]: info: Clearing Spotify queue Apr 07 09:19:16 rivo volumio[5339]: info: CoreCommandRouter::volumioGetQueue Apr 07 09:19:16 rivo volumio[5339]: info: CoreStateMachine::getQueue Apr 07 09:19:16 rivo volumio[5339]: info: CorePlayQueue::getQueue Apr 07 09:19:17 rivo volumio[5339]: info: [1712481557798] ControllerSpotify::pushState Apr 07 09:19:17 rivo volumio[5339]: info: CoreCommandRouter::servicePushState Apr 07 09:19:17 rivo volumio[5339]: info: CoreStateMachine::pushState Apr 07 09:19:17 rivo volumio[5339]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 07 09:19:17 rivo volumio[5339]: info: CoreCommandRouter::volumioPushState Apr 07 09:19:17 rivo volumio[5339]: info: MRS: Pushing multiroomSync output update for this device Apr 07 09:19:17 rivo volumio[5339]: info: MRS: Pushing multiroomSync output Apr 07 09:19:17 rivo volumio[5339]: info: CorePlayQueue::getTrack 0 Apr 07 09:19:17 rivo volumio[5339]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Apr 07 09:19:17 rivo volumio[5339]: info: Signalling Playback active due to playback status change Apr 07 09:19:17 rivo volumio[5339]: info: Signalling Playback active due to playback status change Apr 07 09:19:21 rivo volumio[21925]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SendError("...")', /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/playback/src/player.rs:232:61 Apr 07 09:19:21 rivo volumio[21925]: stack backtrace: Apr 07 09:19:21 rivo volumio[21925]: 0: 0xab6db444 - std::backtrace_rs::backtrace::libunwind::trace::h40a4eff66330a36d Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5 Apr 07 09:19:21 rivo volumio[21925]: 1: 0xab6db444 - std::backtrace_rs::backtrace::trace_unsynchronized::hbce01963451b0cd5 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 Apr 07 09:19:21 rivo volumio[21925]: 2: 0xab6db444 - std::sys_common::backtrace::_print_fmt::h95da650d09c7e00b Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:66:5 Apr 07 09:19:21 rivo volumio[21925]: 3: 0xab6db444 - ::fmt::h33b23b1d14f668ff Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:45:22 Apr 07 09:19:21 rivo volumio[21925]: 4: 0xab7040dc - core::fmt::write::h6320fb0e6ac90e58 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/fmt/mod.rs:1190:17 Apr 07 09:19:21 rivo volumio[21925]: 5: 0xab6d34c4 - std::io::Write::write_fmt::h33b25d4810ca481f Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/io/mod.rs:1657:15 Apr 07 09:19:21 rivo volumio[21925]: 6: 0xab6ddef4 - std::sys_common::backtrace::_print::h7e61c5be69c715ef Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:48:5 Apr 07 09:19:21 rivo volumio[21925]: 7: 0xab6ddef4 - std::sys_common::backtrace::print::h3cee176d7c8dab8b Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:35:9 Apr 07 09:19:21 rivo volumio[21925]: 8: 0xab6ddef4 - std::panicking::default_hook::{{closure}}::h2d0211dd2e97dc43 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:295:22 Apr 07 09:19:21 rivo volumio[21925]: 9: 0xab6ddb14 - std::panicking::default_hook::hcbdb3b7c40dca30c Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:314:9 Apr 07 09:19:21 rivo volumio[21925]: 10: 0xab6de694 - std::panicking::rust_panic_with_hook::h4ce49e7a343dc12b Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:698:17 Apr 07 09:19:21 rivo volumio[21925]: 11: 0xab6de304 - std::panicking::begin_panic_handler::{{closure}}::h4961100fae529fe9 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:588:13 Apr 07 09:19:21 rivo volumio[21925]: 12: 0xab6db9c4 - std::sys_common::backtrace::__rust_end_short_backtrace::hf2e68e62c7a80f1f Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/sys_common/backtrace.rs:138:18 Apr 07 09:19:21 rivo volumio[21925]: 13: 0xab6de098 - rust_begin_unwind Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:584:5 Apr 07 09:19:21 rivo volumio[21925]: 14: 0xab1c16f4 - core::panicking::panic_fmt::h84c42730e4a50809 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/panicking.rs:143:14 Apr 07 09:19:21 rivo volumio[21925]: 15: 0xab1c17c8 - core::result::unwrap_failed::h43118a132315b545 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/result.rs:1749:5 Apr 07 09:19:21 rivo volumio[21925]: 16: 0xab2dbd9c - librespot_playback::player::Player::command::h858bc51b80bfd51a Apr 07 09:19:21 rivo volumio[21925]: 17: 0xab2dbf1c - librespot_playback::player::Player::stop::h301b495d5a97f352 Apr 07 09:19:21 rivo volumio[21925]: 18: 0xab2adf0c - ::poll::h2a7bff75029d3b82 Apr 07 09:19:21 rivo volumio[21925]: 19: 0xab1e92ec - ::poll::h5fd9e3bcdeb25ad9 Apr 07 09:19:21 rivo volumio[21925]: 20: 0xab2063dc - futures::task_impl::std::set::h8f754e80bd562d0a Apr 07 09:19:21 rivo volumio[21925]: 21: 0xab21d42c - std::thread::local::LocalKey::with::h71cfa1e374fcc0a0 Apr 07 09:19:21 rivo volumio[21925]: 22: 0xab20299c - tokio_current_thread::Entered

::block_on::hde55cdf28eabe6d5 Apr 07 09:19:21 rivo volumio[21925]: 23: 0xab21d6f0 - std::thread::local::LocalKey::with::hedba3cfe41326627 Apr 07 09:19:21 rivo volumio[21925]: 24: 0xab205880 - tokio::runtime::current_thread::runtime::Runtime::block_on::h60d5b89560100ed8 Apr 07 09:19:21 rivo volumio[21925]: 25: 0xab1ebeb0 - vollibrespot::main::h35555355ed947dd1 Apr 07 09:19:21 rivo volumio[21925]: 26: 0xab20bc50 - std::sys_common::backtrace::__rust_begin_short_backtrace::hef626a10d324c12a Apr 07 09:19:21 rivo volumio[21925]: 27: 0xab23152c - std::rt::lang_start::{{closure}}::hd80188e4bcac5072 Apr 07 09:19:21 rivo volumio[21925]: 28: 0xab6dab28 - core::ops::function::impls:: for &F>::call_once::h0567da839a080232 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/core/src/ops/function.rs:259:13 Apr 07 09:19:21 rivo volumio[21925]: 29: 0xab6dab28 - std::panicking::try::do_call::hdf194554a41aa3cc Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:492:40 Apr 07 09:19:21 rivo volumio[21925]: 30: 0xab6dab28 - std::panicking::try::hbf4b7be9f9ffa5f8 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:456:19 Apr 07 09:19:21 rivo volumio[21925]: 31: 0xab6dab28 - std::panic::catch_unwind::h45f392a39f2fe48c Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panic.rs:137:14 Apr 07 09:19:21 rivo volumio[21925]: 32: 0xab6dab28 - std::rt::lang_start_internal::{{closure}}::hd772cb03c2060671 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/rt.rs:128:48 Apr 07 09:19:21 rivo volumio[21925]: 33: 0xab6dab28 - std::panicking::try::do_call::hd126f715b519ff2a Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:492:40 Apr 07 09:19:21 rivo volumio[21925]: 34: 0xab6dab28 - std::panicking::try::h80b7148ce71893dc Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panicking.rs:456:19 Apr 07 09:19:21 rivo volumio[21925]: 35: 0xab6dab28 - std::panic::catch_unwind::h1562f0b2e8a9cb0d Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/panic.rs:137:14 Apr 07 09:19:21 rivo volumio[21925]: 36: 0xab6dab28 - std::rt::lang_start_internal::h3daa586a0b835507 Apr 07 09:19:21 rivo volumio[21925]: at /rustc/7737e0b5c4103216d6fd8cf941b7ab9bdbaace7c/library/std/src/rt.rs:128:20 Apr 07 09:19:21 rivo volumio[21925]: 37: 0xab1ede80 - main Apr 07 09:19:21 rivo volumio[21925]: 38: 0xf6e6c524 - __libc_start_main Apr 07 09:19:21 rivo volumio[21925]: [Vollibrespot] : Player thread panicked! Apr 07 09:19:21 rivo volumio[21925]: [Vollibrespot] : EventSender disconnected Apr 07 09:19:21 rivo volumio[5339]: [SpotifyConnect] PlaybackInactive Apr 07 09:19:21 rivo volumio[5339]: info: [1712481561620] ControllerSpotify::pushState Apr 07 09:19:21 rivo volumio[5339]: info: CoreCommandRouter::servicePushState Apr 07 09:19:21 rivo volumio[5339]: info: CoreStateMachine::pushState Apr 07 09:19:21 rivo volumio[5339]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 07 09:19:21 rivo volumio[5339]: info: CoreCommandRouter::volumioPushState Apr 07 09:19:21 rivo volumio[5339]: info: MRS: Pushing multiroomSync output update for this device Apr 07 09:19:21 rivo volumio[5339]: info: MRS: Pushing multiroomSync output Apr 07 09:19:21 rivo systemd[1]: volspotconnect.service: Main process exited, code=exited, status=101/n/a Apr 07 09:19:21 rivo systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Apr 07 09:19:21 rivo volumio[5339]: info: MCU Signalled Playback Inactive Apr 07 09:19:23 rivo systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Apr 07 09:19:23 rivo systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 1. Apr 07 09:19:23 rivo systemd[1]: Stopped Volspotconnect2 Daemon. Apr 07 09:19:23 rivo systemd[1]: Started Volspotconnect2 Daemon. Apr 07 09:19:23 rivo volumio[27881]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Apr 07 09:19:23 rivo volumio[27881]: Reading Config from "/tmp/volspotify.toml" Apr 07 09:19:23 rivo volumio[27881]: [Vollibrespot] : Using Alsa backend with device: volumio Apr 07 09:19:23 rivo volumio[27881]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Apr 07 09:19:40 rivo volumio[5339]: info: MCU Signalled Playback Active Apr 07 09:20:09 rivo volumio[5339]: info: CoreCommandRouter::servicePushState Apr 07 09:20:09 rivo volumio[5339]: info: CoreStateMachine::pushState Apr 07 09:20:09 rivo volumio[5339]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 07 09:20:09 rivo volumio[5339]: info: CoreCommandRouter::volumioPushState Apr 07 09:20:09 rivo volumio[5339]: info: MRS: Pushing multiroomSync output update for this device Apr 07 09:20:09 rivo volumio[5339]: info: MRS: Pushing multiroomSync output Apr 07 09:20:09 rivo volumio[5339]: info: CoreCommandRouter::servicePushState Apr 07 09:20:09 rivo volumio[5339]: info: CoreStateMachine::pushState Apr 07 09:20:09 rivo volumio[5339]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 07 09:20:09 rivo volumio[5339]: info: CoreCommandRouter::volumioPushState Apr 07 09:20:09 rivo volumio[5339]: info: MRS: Pushing multiroomSync output update for this device Apr 07 09:20:09 rivo volumio[5339]: info: MRS: Pushing multiroomSync output Apr 07 09:20:09 rivo volumio[5339]: info: MCU Signalled Playback Inactive Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Authenticated as "1130199296" ! Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Using alsa sink Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Country: "NL" Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Metadata pipe established Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Event: Volume { volume_to_mixer: 64511 } Apr 07 09:20:11 rivo volumio[5339]: [SpotifyConnect] Volume Spotify: 98.43747615777828 Volumio: 98 Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Fetching autoplay context uri Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Event: SessionActive { became_active_at: 1712481611739 } Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : SessionActive! Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 119414075360767724878697810268775955797, audio_type: Track } } Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 119414075360767724878697810268775955797, audio_type: Track } } Apr 07 09:20:11 rivo volumio[5339]: [SpotifyConnect] A connect session has begun Apr 07 09:20:11 rivo volumio[5339]: info: Acquiring new spotify session Apr 07 09:20:11 rivo volumio[5339]: info: CoreCommandRouter::volumioStop Apr 07 09:20:11 rivo volumio[5339]: info: CoreStateMachine::stop Apr 07 09:20:11 rivo volumio[5339]: info: CoreStateMachine::serviceStop Apr 07 09:20:11 rivo volumio[5339]: info: CoreCommandRouter::serviceStop Apr 07 09:20:11 rivo volumio[5339]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 07 09:20:11 rivo volumio[5339]: TypeError: Cannot read property 'then' of undefined Apr 07 09:20:11 rivo volumio[5339]: at SpotConnEvents. (/data/plugins/music_service/spop/index.js:2132:31) Apr 07 09:20:11 rivo volumio[5339]: at SpotConnEvents.emit (events.js:400:28) Apr 07 09:20:11 rivo volumio[5339]: at SpotConnEvents.parseData (/data/plugins/music_service/spop/SpotConnController.js:92:16) Apr 07 09:20:11 rivo volumio[5339]: at Socket. (/data/plugins/music_service/spop/SpotConnController.js:15:12) Apr 07 09:20:11 rivo volumio[5339]: at Socket.emit (events.js:400:28) Apr 07 09:20:11 rivo volumio[5339]: at UDP.onMessage [as onmessage] (dgram.js:931:8) Apr 07 09:20:11 rivo volumio[5339]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:0bNkIzGVewls8b0UP1Ki92"> Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Resolving uri "spotify:station:playlist:0bNkIzGVewls8b0UP1Ki92" Apr 07 09:20:11 rivo vtcs[21998]: [2024-04-07 09:20:11] [info] asio async_shutdown error: asio.misc:2 (End of file) Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQA7-UNOdy2lxY6YMXjZp68glfDvAJYz-oRKeV8fFK02IJx4g0F3CwT_q-ITLDrsF5a9I2QJJx31qRwRrSSlB9f6VYd1fwEU3QRxmNarZTRkzWlg5RoEaHb-z_p3ruY3EOuAfaUN_Kckvo62da4pyxSdCWjVuiAk0p4jWJfysM1CmBoZuyhNRb7WI0oQYqVbkVkjOg", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Apr 07 09:20:11 rivo volumio[27881]: [Vollibrespot] : Loading with Spotify URI Apr 07 09:20:11 rivo vtcs[21998]: [2024-04-07 09:20:11.976] [tisoc] [warning] [PlaybackControllerImpl.cpp:501] Illegal state:0 Apr 07 09:20:12 rivo volumio[27881]: [Vollibrespot] : (217915 ms) loaded Apr 07 09:20:12 rivo volumio[27881]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:0bNkIzGVewls8b0UP1Ki92"> Apr 07 09:20:12 rivo volumio[27881]: [Vollibrespot] : Event: SinkActive Apr 07 09:20:12 rivo sudo[27938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-07 09:19 Apr 07 09:20:12 rivo sudo[27938]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 11:41:55 AM CET" VOLUMIO_VERSION="3.629" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b0437c7088d6645a661a49f6d9fa596a"