-- Logs begin at Mon 2025-01-20 20:18:20 UTC, end at Mon 2025-06-02 19:49:39 UTC. -- Jun 02 19:48:00 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:06 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:11 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:17 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:22 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:28 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:34 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:39 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:45 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:50 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:48:56 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:02 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: Pushing metadata Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreCommandRouter::servicePushState Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreStateMachine::pushState Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioPushState Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreCommandRouter::servicePushState Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreStateMachine::pushState Jun 02 19:49:02 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioPushState Jun 02 19:49:03 wizard-iv-fn volumio[932]: info: CoreCommandRouter::servicePushState Jun 02 19:49:03 wizard-iv-fn volumio[932]: info: CoreStateMachine::pushState Jun 02 19:49:03 wizard-iv-fn volumio[932]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 19:49:03 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioPushState Jun 02 19:49:07 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:13 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:14 wizard-iv-fn vtcs[1810]: [2025-06-02 19:49:14] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jun 02 19:49:14 wizard-iv-fn vtcs[1810]: [2025-06-02 19:49:14] [info] asio async_shutdown error: asio.system:32 (Broken pipe) Jun 02 19:49:18 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:24 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: Pushing metadata Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreCommandRouter::servicePushState Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreStateMachine::pushState Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioPushState Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreCommandRouter::servicePushState Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreStateMachine::pushState Jun 02 19:49:27 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioPushState Jun 02 19:49:30 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:35 wizard-iv-fn wpa_supplicant[739]: wlan0: Failed to initiate sched scan Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Authenticated as "frits.neuteboom" ! Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0 Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-10000)[dB]) -- max: 100 (MilliBel(0)[dB]) HW: true Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Using alsa sink Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Metadata pipe established Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Country: "NL" Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } Jun 02 19:49:37 wizard-iv-fn volumio[932]: [SpotifyConnect] 0 Jun 02 19:49:37 wizard-iv-fn volumio[932]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0 Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreStateMachine::pushState Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioPushState Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Event: SessionActive { became_active_at: 1748893777834 } Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : SessionActive! Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Fetching autoplay context uri Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 321265425217728186690608597320112581594, audio_type: Track } } Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 321265425217728186690608597320112581594, audio_type: Track } } Jun 02 19:49:37 wizard-iv-fn volumio[932]: [SpotifyConnect] A connect session has begun Jun 02 19:49:37 wizard-iv-fn volumio[932]: [SpotifyConnect] Device palyback is active! Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:3VG8mGTDwAxUPwbIi0AFFQ"> Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Resolving uri "spotify:station:playlist:3VG8mGTDwAxUPwbIi0AFFQ" Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioGetState Jun 02 19:49:37 wizard-iv-fn volumio[932]: [SpotifyConnect] Currently active: tidalconnect Jun 02 19:49:37 wizard-iv-fn volumio[932]: [SpotifyConnect] Stopping currently active service Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreCommandRouter::volumioStop Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreStateMachine::stop Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreStateMachine::serviceStop Jun 02 19:49:37 wizard-iv-fn volumio[932]: info: CoreCommandRouter::serviceStop Jun 02 19:49:37 wizard-iv-fn volumio[932]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 19:49:37 wizard-iv-fn vtcs[1810]: [2025-06-02 19:49:37] [info] asio async_shutdown error: asio.misc:2 (End of file) Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQAN7QI_5poBTY_mDyp8nj0OQNn-tZKjO8evrmSC5F5pA9qCG2X9PD58_Y29bfEE2SGIeh4ipLfSsLnbjVgYqxfXlKN19Oo0Kijxg5fZgjdLOKPHPfD6zgvCfY14NnvNh1MTzfx4f8ybcSjw7-oRUH5eN6KeFKqeDmxgwoekOWZv3BC1XmjHizFMZjLBStHUJgMVdMY0YBunkKTzB4PoBldvZtrSfbMTkLSW-LjMQVWkj8X_ROm5", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Jun 02 19:49:37 wizard-iv-fn volumio[932]: TypeError: Cannot read property 'then' of undefined Jun 02 19:49:37 wizard-iv-fn volumio[932]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:143:23) Jun 02 19:49:37 wizard-iv-fn volumio[932]: at SpotConnEvents.emit (events.js:315:20) Jun 02 19:49:37 wizard-iv-fn volumio[932]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Jun 02 19:49:37 wizard-iv-fn volumio[932]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Jun 02 19:49:37 wizard-iv-fn volumio[932]: at Socket.emit (events.js:315:20) Jun 02 19:49:37 wizard-iv-fn volumio[932]: at UDP.onMessage [as onmessage] (dgram.js:919:8) Jun 02 19:49:37 wizard-iv-fn volumio[932]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 19:49:37 wizard-iv-fn volumio[1789]: [Vollibrespot] : Loading with Spotify URI Jun 02 19:49:38 wizard-iv-fn volumio[1789]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:3VG8mGTDwAxUPwbIi0AFFQ"> Jun 02 19:49:38 wizard-iv-fn volumio[1789]: [Vollibrespot] : (473540 ms) loaded Jun 02 19:49:38 wizard-iv-fn volumio[1789]: [Vollibrespot] : Event: SinkActive Jun 02 19:49:39 wizard-iv-fn sudo[2752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-02 19:48 Jun 02 19:49:39 wizard-iv-fn sudo[2752]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e5f8795c07ba36ff2b02d7ba0a21c7a0f29b897e" VOLUMIO_FE_VERSION="473d8facbed5f9754db84a81b093baace7aa4b64" VOLUMIO_FE3_VERSION="934cddf6d46478e7a53a8d3664cd346f4de7cb34" VOLUMIO_BE_VERSION="359b2717b79cfc72b7d1c918d0fc2885a93bca70" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 24 Jan 2022 10:51:57 AM CET" VOLUMIO_VERSION="3.198" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="74e6a9ad035e912732893c8d6b060b17"