-- Logs begin at Sat 2025-12-06 11:54:35 UTC, end at Sun 2025-12-07 19:39:33 UTC. -- Dec 07 19:38:02 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:08 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:13 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:19 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:25 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:30 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:36 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:42 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:47 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:53 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:38:58 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:04 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:10 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:15 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:21 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:26 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:31 wizard-iv-fn volumio[1963]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Authenticated as "frits.neuteboom" ! Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0 Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-10000)[dB]) -- max: 100 (MilliBel(0)[dB]) HW: true Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Using alsa sink Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Metadata pipe established Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Country: "NL" Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } Dec 07 19:39:32 wizard-iv-fn volumio[897]: [SpotifyConnect] 0 Dec 07 19:39:32 wizard-iv-fn volumio[897]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0 Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreStateMachine::pushState Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreCommandRouter::volumioPushState Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Event: SessionActive { became_active_at: 1765136372473 } Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : SessionActive! Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Fetching autoplay context uri Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 8250050833847105862219960281762932575, audio_type: Track } } Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 8250050833847105862219960281762932575, audio_type: Track } } Dec 07 19:39:32 wizard-iv-fn volumio[897]: [SpotifyConnect] A connect session has begun Dec 07 19:39:32 wizard-iv-fn volumio[897]: [SpotifyConnect] Device palyback is active! Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreCommandRouter::volumioGetState Dec 07 19:39:32 wizard-iv-fn volumio[897]: [SpotifyConnect] Currently active: tidalconnect Dec 07 19:39:32 wizard-iv-fn volumio[897]: [SpotifyConnect] Stopping currently active service Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreCommandRouter::volumioStop Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreStateMachine::stop Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreStateMachine::serviceStop Dec 07 19:39:32 wizard-iv-fn volumio[897]: info: CoreCommandRouter::serviceStop Dec 07 19:39:32 wizard-iv-fn volumio[897]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 19:39:32 wizard-iv-fn vtcs[1997]: [2025-12-07 19:39:32.496] [tisoc] [warning] [PlaybackControllerImpl.cpp:472] Illegal state:0 Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:37i9dQZF1E37Zla3pUWXkY"> Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Resolving uri "spotify:station:playlist:37i9dQZF1E37Zla3pUWXkY" Dec 07 19:39:32 wizard-iv-fn volumio[897]: TypeError: Cannot read property 'then' of undefined Dec 07 19:39:32 wizard-iv-fn volumio[897]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:143:23) Dec 07 19:39:32 wizard-iv-fn volumio[897]: at SpotConnEvents.emit (events.js:315:20) Dec 07 19:39:32 wizard-iv-fn volumio[897]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Dec 07 19:39:32 wizard-iv-fn volumio[897]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Dec 07 19:39:32 wizard-iv-fn volumio[897]: at Socket.emit (events.js:315:20) Dec 07 19:39:32 wizard-iv-fn volumio[897]: at UDP.onMessage [as onmessage] (dgram.js:919:8) Dec 07 19:39:32 wizard-iv-fn volumio[897]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQBT64CNi9f3KHxfICCuKv3yUHAx43Y-JKfTtI7QvxqfwGeU7lL-DNPzxrHaqs2aXbnXcYjC85Ka3BCas3lCOk0Z-OxCXtTxT6UqUD8CS4ZFZCvzkQxq_ir5Vf92j39vbCpRFGY1iUvA2_x0BRumG1O9brd9KqiOgHA6u6LJI3JNtt6pTS2Nh8r_IaeUVo2txKmjfW__jFBmrz_5oP1wEepvQJnXTOa1QGKaTsJNQfEmJr8NMKvup4a9", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-modify-playback-state", "user-read-playback-state", "user-read-currently-playing", "user-read-private"] } } Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Loading with Spotify URI Dec 07 19:39:32 wizard-iv-fn wpa_supplicant[732]: wlan0: Failed to initiate sched scan Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:37i9dQZF1E37Zla3pUWXkY"> Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : (259845 ms) loaded Dec 07 19:39:32 wizard-iv-fn volumio[1963]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 8250050833847105862219960281762932575, audio_type: Track } } Dec 07 19:39:33 wizard-iv-fn sudo[30924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-07 19:38 Dec 07 19:39:33 wizard-iv-fn sudo[30924]: 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"