-- Logs begin at Mon 2025-01-20 20:18:20 UTC, end at Fri 2025-09-05 15:09:34 UTC. -- Sep 05 15:08:05 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:11 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:16 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:22 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:28 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:33 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:39 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:44 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:50 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:08:56 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:01 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:07 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:12 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:18 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:24 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:29 wizard-iv-fn wpa_supplicant[798]: wlan0: Failed to initiate sched scan Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Authenticated as "frits.neuteboom" ! Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0 Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-10000)[dB]) -- max: 100 (MilliBel(0)[dB]) HW: true Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Using alsa sink Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Metadata pipe established Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Country: "NL" Sep 05 15:09:32 wizard-iv-fn volumio[1742]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } Sep 05 15:09:32 wizard-iv-fn volumio[902]: [SpotifyConnect] 0 Sep 05 15:09:32 wizard-iv-fn volumio[902]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0 Sep 05 15:09:32 wizard-iv-fn volumio[902]: info: CoreStateMachine::pushState Sep 05 15:09:32 wizard-iv-fn volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 05 15:09:32 wizard-iv-fn volumio[902]: info: CoreCommandRouter::volumioPushState Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : Event: SessionActive { became_active_at: 1757084973420 } Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : SessionActive! Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : Fetching autoplay context uri Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 273288257184286276885547659670715059713, audio_type: Track } } Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 273288257184286276885547659670715059713, audio_type: Track } } Sep 05 15:09:33 wizard-iv-fn volumio[902]: [SpotifyConnect] A connect session has begun Sep 05 15:09:33 wizard-iv-fn volumio[902]: [SpotifyConnect] Device palyback is active! Sep 05 15:09:33 wizard-iv-fn volumio[902]: info: CoreCommandRouter::volumioGetState Sep 05 15:09:33 wizard-iv-fn volumio[902]: [SpotifyConnect] Currently active: tidalconnect Sep 05 15:09:33 wizard-iv-fn volumio[902]: [SpotifyConnect] Stopping currently active service Sep 05 15:09:33 wizard-iv-fn volumio[902]: info: CoreCommandRouter::volumioStop Sep 05 15:09:33 wizard-iv-fn volumio[902]: info: CoreStateMachine::stop Sep 05 15:09:33 wizard-iv-fn volumio[902]: info: CoreStateMachine::serviceStop Sep 05 15:09:33 wizard-iv-fn volumio[902]: info: CoreCommandRouter::serviceStop Sep 05 15:09:33 wizard-iv-fn volumio[902]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri=spotify:search:nod+krai+main+theme Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : AutoplayError: MercuryError Sep 05 15:09:33 wizard-iv-fn volumio[902]: TypeError: Cannot read property 'then' of undefined Sep 05 15:09:33 wizard-iv-fn volumio[902]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:143:23) Sep 05 15:09:33 wizard-iv-fn volumio[902]: at SpotConnEvents.emit (events.js:315:20) Sep 05 15:09:33 wizard-iv-fn volumio[902]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Sep 05 15:09:33 wizard-iv-fn volumio[902]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Sep 05 15:09:33 wizard-iv-fn volumio[902]: at Socket.emit (events.js:315:20) Sep 05 15:09:33 wizard-iv-fn volumio[902]: at UDP.onMessage [as onmessage] (dgram.js:919:8) Sep 05 15:09:33 wizard-iv-fn volumio[902]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQDDQyUPdADRrs8loKON_ZObjvSKLUoWAMswBDwNPU_qUv-qOuv3kuSqjkLXCUcHV_HTwcvSEE6AXkFASPzKl--nHMADeIlLlt9zXVyPiBEccQB6Lf5_Hk6zlj1gO7C5yXxRDkbtkKU0gHjbHhbkiaRo_qiou4QfsvHKgCvlqg6tZSxafwjbOtRXC0AT_8GTgWOfYdszqNhpzKAzOPT_nGjA1HG32ptKNl22szcBT6eSZPHFZtHe", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-modify-playback-state", "user-read-playback-state", "user-read-currently-playing", "user-read-private"] } } Sep 05 15:09:33 wizard-iv-fn vtcs[1763]: [2025-09-05 15:09:33] [info] asio async_shutdown error: asio.misc:2 (End of file) Sep 05 15:09:33 wizard-iv-fn volumio[1742]: [Vollibrespot] : Loading with Spotify URI Sep 05 15:09:33 wizard-iv-fn vtcs[1763]: [2025-09-05 15:09:33.474] [tisoc] [warning] [PlaybackControllerImpl.cpp:472] Illegal state:0 Sep 05 15:09:34 wizard-iv-fn volumio[1742]: [Vollibrespot] : (190441 ms) loaded Sep 05 15:09:34 wizard-iv-fn volumio[1742]: [Vollibrespot] : Event: SinkActive Sep 05 15:09:34 wizard-iv-fn sudo[4708]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-05 15:08 Sep 05 15:09:34 wizard-iv-fn sudo[4708]: 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"