-- Logs begin at Fri 2025-12-26 22:22:13 UTC, end at Fri 2025-12-26 22:44:42 UTC. -- Dec 26 22:43:13 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:43:13 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:43:13 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:43:13 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:43:13 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:43:13 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:43:13 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:43:13 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:43:16 tntvolumio shairport-sync[1086]: {"time":1766788596579,"response":"stopAirplay Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 26 22:43:16 tntvolumio shairport-sync[1086]: Dload Upload Total Spent Left Speed Dec 26 22:43:16 tntvolumio volumio[843]: info: Dec 26 22:43:16 tntvolumio volumio[843]: ---------------------------- Client requests Start Airplay metadata parsing Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , airPlayStop Dec 26 22:43:16 tntvolumio volumio[843]: UNSET VOLATILE Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::resetVolumioState Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::getcurrentVolume Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreCommandRouter::volumioRetrievevolume Dec 26 22:43:16 tntvolumio shairport-sync[1086]: [155B blob data] Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::updateTrackBlock Dec 26 22:43:16 tntvolumio volumio[843]: info: CorePlayQueue::getTrackBlock Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreCommandRouter::volumioStop Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::stop Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 26 22:43:16 tntvolumio volumio[843]: UNSET VOLATILE Dec 26 22:43:16 tntvolumio volumio[843]: info: VolumeController:: Volume=33 Mute =true Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:43:16 tntvolumio volumio[843]: info: CorePlayQueue::getTrack 0 Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:43:16 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:43:16 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:43:16 tntvolumio volumio[843]: info: Pushing Favourites {"service":"mpd","uri":"mnt/NAS/TnTMedia/Music/iTunes/iTunes Music/April Wine/Hot Shots/April Wine - Here For A Good Time.mp3","favourite":false} Dec 26 22:43:46 tntvolumio volumio[843]: info: CoreCommandRouter::volumioStop Dec 26 22:43:46 tntvolumio volumio[843]: info: CoreStateMachine::stop Dec 26 22:43:46 tntvolumio volumio[843]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 26 22:43:46 tntvolumio volumio[843]: UNSET VOLATILE Dec 26 22:43:46 tntvolumio volumio[843]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 26 22:43:46 tntvolumio volumio[843]: info: Airplay started streaming Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:43:48 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:43:48 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:43:48 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:43:48 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:43:48 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:44:14 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:44:14 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:44:14 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:44:14 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:44:14 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::servicePushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::syncState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::volumioPushState Dec 26 22:44:14 tntvolumio volumio[843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 26 22:44:14 tntvolumio volumio[843]: info: interfaceApi::pushState Dec 26 22:44:14 tntvolumio volumio[843]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false} Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Event: SessionActive { became_active_at: 1766789079045 } Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : SessionActive! Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Fetching autoplay context uri Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 230691462404109774136614324359694069964, audio_type: Track } } Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 230691462404109774136614324359694069964, audio_type: Track } } Dec 26 22:44:39 tntvolumio volumio[843]: [SpotifyConnect] A connect session has begun Dec 26 22:44:39 tntvolumio volumio[843]: [SpotifyConnect] Device palyback is active! Dec 26 22:44:39 tntvolumio volumio[843]: info: CoreCommandRouter::volumioGetState Dec 26 22:44:39 tntvolumio volumio[843]: info: CoreStateMachine::getState Dec 26 22:44:39 tntvolumio volumio[843]: [SpotifyConnect] Currently active: airplay Dec 26 22:44:39 tntvolumio volumio[843]: [SpotifyConnect] Stopping currently active service Dec 26 22:44:39 tntvolumio volumio[843]: info: CoreCommandRouter::volumioStop Dec 26 22:44:39 tntvolumio volumio[843]: info: CoreStateMachine::stop Dec 26 22:44:39 tntvolumio volumio[843]: info: CoreStateMachine::serviceStop Dec 26 22:44:39 tntvolumio volumio[843]: info: CoreCommandRouter::serviceStop Dec 26 22:44:39 tntvolumio volumio[843]: error: WARNING: No stop method for service airplay Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:track:2R4rDMOdyQYirHkjtBsqYG"> Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Resolving uri "spotify:station:track:2R4rDMOdyQYirHkjtBsqYG" Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQDKKdL6N8slAmHeGnvQJxI95_ZfnL-yD8nE7h511VNbf1OWIxd5sMaqHhuYuuuCR-76QWQXC8gTtdCY0lRQETXMnYJsdUP3cjLTaVlDxqoFwYhCiTQqPEzY4oQuO5if4x_8e1SvgnW6Xfa0A6fi6wc6lptXEbhC_TwHavD1eWB-qTOaOJgmgboG5pcdNzZe43ALD-Wk-1Nr6TmNy5rgmw_3oG3X7MSHpvwEWK53fnBM9FeP_lNzfB8am-ks8VR60d4nEg", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-modify-playback-state", "user-read-playback-state", "user-read-currently-playing", "user-read-private"] } } Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Loading with Spotify URI Dec 26 22:44:39 tntvolumio volumio[1059]: [Vollibrespot] : Resolved 50 tracks from <"spotify:track:2R4rDMOdyQYirHkjtBsqYG"> Dec 26 22:44:39 tntvolumio volumio[843]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 26 22:44:39 tntvolumio volumio[843]: TypeError: Cannot read property 'then' of undefined Dec 26 22:44:39 tntvolumio volumio[843]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23) Dec 26 22:44:39 tntvolumio volumio[843]: at emitNone (events.js:106:13) Dec 26 22:44:39 tntvolumio volumio[843]: at SpotConnEvents.emit (events.js:208:7) Dec 26 22:44:39 tntvolumio volumio[843]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Dec 26 22:44:39 tntvolumio volumio[843]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Dec 26 22:44:39 tntvolumio volumio[843]: at emitTwo (events.js:126:13) Dec 26 22:44:39 tntvolumio volumio[843]: at Socket.emit (events.js:214:7) Dec 26 22:44:39 tntvolumio volumio[843]: at UDP.onMessage [as onmessage] (dgram.js:659:8) Dec 26 22:44:39 tntvolumio volumio[843]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : (190973 ms) loaded Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' Dec 26 22:44:40 tntvolumio volumio[1059]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed Dec 26 22:44:40 tntvolumio volumio[1059]: 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 Dec 26 22:44:40 tntvolumio volumio[1059]: stack backtrace: Dec 26 22:44:40 tntvolumio volumio[1059]: 0: 0xd763e38 - backtrace::backtrace::libunwind::trace::ha66f0a58dafef379 Dec 26 22:44:40 tntvolumio volumio[1059]: at /cargo/registry/src/github.com-1285ae84e5963aae/backtrace-0.3.46/src/backtrace/libunwind.rs:86 Dec 26 22:44:40 tntvolumio volumio[1059]: 1: 0xd763e38 - backtrace::backtrace::trace_unsynchronized::h1af62022ad7ddee3 Dec 26 22:44:40 tntvolumio volumio[1059]: at /cargo/registry/src/github.com-1285ae84e5963aae/backtrace-0.3.46/src/backtrace/mod.rs:66 Dec 26 22:44:40 tntvolumio volumio[1059]: 2: 0xd763e38 - std::sys_common::backtrace::_print_fmt::hb97d84e219f64b39 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/sys_common/backtrace.rs:78 Dec 26 22:44:40 tntvolumio volumio[1059]: 3: 0xd763e38 - ::fmt::h100f5a82407b68e4 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/sys_common/backtrace.rs:59 Dec 26 22:44:40 tntvolumio volumio[1059]: 4: 0xd78de80 - core::fmt::write::he118d0604e33df81 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libcore/fmt/mod.rs:1076 Dec 26 22:44:40 tntvolumio volumio[1059]: 5: 0xd75d71c - std::io::Write::write_fmt::h003436247c3fc214 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/io/mod.rs:1537 Dec 26 22:44:40 tntvolumio volumio[1059]: 6: 0xd76676e - std::sys_common::backtrace::_print::h83f536c912b08532 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/sys_common/backtrace.rs:62 Dec 26 22:44:40 tntvolumio volumio[1059]: 7: 0xd76676e - std::sys_common::backtrace::print::h89499a5fd474cd45 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/sys_common/backtrace.rs:49 Dec 26 22:44:40 tntvolumio volumio[1059]: 8: 0xd76676e - std::panicking::default_hook::{{closure}}::h105742511edf80c2 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/panicking.rs:198 Dec 26 22:44:40 tntvolumio volumio[1059]: 9: 0xd766498 - std::panicking::default_hook::h4b1ff4bee1a0989c Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/panicking.rs:217 Dec 26 22:44:40 tntvolumio volumio[1059]: 10: 0xd766e16 - std::panicking::rust_panic_with_hook::h403abc20e0fb824f Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/panicking.rs:526 Dec 26 22:44:40 tntvolumio volumio[1059]: 11: 0xd7669c8 - rust_begin_unwind Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/panicking.rs:437 Dec 26 22:44:40 tntvolumio volumio[1059]: 12: 0xd78bab0 - core::panicking::panic_fmt::h280e963ddd15a643 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libcore/panicking.rs:85 Dec 26 22:44:40 tntvolumio volumio[1059]: 13: 0xd78b9ec - core::panicking::panic::h9ccc1b62a8119bd7 Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libcore/panicking.rs:50 Dec 26 22:44:40 tntvolumio volumio[1059]: 14: 0xd360f8d - ::write::h3581324fecd47df1 Dec 26 22:44:40 tntvolumio volumio[1059]: 15: 0xd339ac6 - ::poll::hc21f5ecf7ce2e698 Dec 26 22:44:40 tntvolumio volumio[1059]: 16: 0xd24fe66 - futures::task_impl::std::set::h7d1d91c2a2b6f5b8 Dec 26 22:44:40 tntvolumio volumio[1059]: 17: 0xd245055 - futures::task_impl::Spawn::poll_future_notify::h66f1553db90c4a22 Dec 26 22:44:40 tntvolumio volumio[1059]: 18: 0xd25d76c - futures::future::Future::wait::hfe836d397a4aec59 Dec 26 22:44:40 tntvolumio volumio[1059]: 19: 0xd2466e6 - std::sys_common::backtrace::__rust_begin_short_backtrace::h5ece287f9f454f8f Dec 26 22:44:40 tntvolumio volumio[1059]: 20: 0xd2644ab - core::ops::function::FnOnce::call_once{{vtable.shim}}::he930b09a4d23e04c Dec 26 22:44:40 tntvolumio volumio[1059]: 21: 0xd76a2ef - as core::ops::function::FnOnce>::call_once::h248edc50ac6013fc Dec 26 22:44:40 tntvolumio volumio[1059]: at /rustc/04488afe34512aa4c33566eb16d8c912a3ae04f9/src/liballoc/boxed.rs:1081 Dec 26 22:44:40 tntvolumio volumio[1059]: 22: 0xd76a2ef - as core::ops::function::FnOnce>::call_once::h97a26f5b6bb26bb1 Dec 26 22:44:40 tntvolumio volumio[1059]: at /rustc/04488afe34512aa4c33566eb16d8c912a3ae04f9/src/liballoc/boxed.rs:1081 Dec 26 22:44:40 tntvolumio volumio[1059]: 23: 0xd76a2ef - std::sys::unix::thread::Thread::new::thread_start::h74eb381cbdc8573a Dec 26 22:44:40 tntvolumio volumio[1059]: at src/libstd/sys/unix/thread.rs:87 Dec 26 22:44:40 tntvolumio volumio[1059]: 24: 0xb372cd67 - start_thread Dec 26 22:44:41 tntvolumio volumio[1059]: 25: 0xb366c64e - clone Dec 26 22:44:41 tntvolumio volumio[1059]: 26: 0x0 - Dec 26 22:44:42 tntvolumio sudo[11257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-26 22:43 Dec 26 22:44:42 tntvolumio sudo[11257]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 8 (jessie)" NAME="Debian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=debian HOME_URL="http://www.debian.org/" SUPPORT_URL="http://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="2f09878fca434492a3a1c8d64c992c38a304bdcb" VOLUMIO_FE_VERSION="81c7100e9c7342b16fc9e0ca5908a26771e08c4f" VOLUMIO_BE_VERSION="9ddaa4edade219b4424aaf553d8a153e2d73143a" VOLUMIO_ARCH="x86" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Jun 15 20:45:03 CEST 2018" VOLUMIO_VERSION="2.411" VOLUMIO_HARDWARE="x86"