Feb 11 09:24:00 music go-librespot[25252]: time="2026-02-11T09:24:00-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 11 09:24:00 music go-librespot[25252]: time="2026-02-11T09:24:00-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:00 music go-librespot[25252]: time="2026-02-11T09:24:00-05:00" level=debug msg="completed challenge" Feb 11 09:24:00 music go-librespot[25252]: time="2026-02-11T09:24:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:00 music go-librespot[25252]: time="2026-02-11T09:24:00-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:00 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:00 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:01 music volumio[25236]: info: Starting UPNP Browser Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "alarm-clock"... Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "airplay_emulation"... Feb 11 09:24:01 music volumio[25236]: info: Starting Shairport Sync Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "last_100"... Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "webradio"... Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "i2s_dacs"... Feb 11 09:24:01 music volumio[25236]: info: I2S DAC not set, start Auto-detection Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "volumiodiscovery"... Feb 11 09:24:01 music volumio[25236]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:01 music volumio[25236]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:01 music volumio[25236]: *** WARNING *** For more information see Feb 11 09:24:01 music volumio[25236]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:01 music volumio[25236]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:01 music volumio[25236]: *** WARNING *** For more information see Feb 11 09:24:01 music node[25236]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:01 music node[25236]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:01 music node[25236]: *** WARNING *** For more information see Feb 11 09:24:01 music node[25236]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:01 music node[25236]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:01 music node[25236]: *** WARNING *** For more information see Feb 11 09:24:01 music volumio[25236]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 09:24:01 music volumio[25236]: info: Discovery: Started advertising with name: music Feb 11 09:24:01 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:01 music volumio[25236]: info: Loading plugin "spop"... Feb 11 09:24:02 music volumio[25236]: info: Loading plugin "outputs"... Feb 11 09:24:02 music volumio[25236]: info: Loading plugin "albumart"... Feb 11 09:24:02 music volumio[25236]: info: Plugin example_plugin is not enabled Feb 11 09:24:02 music volumio[25236]: info: Loading plugin "inputs"... Feb 11 09:24:02 music volumio[25236]: info: Loading plugin "updater_comm"... Feb 11 09:24:02 music volumio[25236]: info: Plugin mpdemulation is not enabled Feb 11 09:24:02 music volumio[25236]: info: Loading plugin "rest_api"... Feb 11 09:24:02 music volumio[25236]: info: Loading plugin "websocket"... Feb 11 09:24:02 music volumio[25236]: info: Starting Socket.io Server version 1.7.4 Feb 11 09:24:02 music volumio[25236]: info: Loading i18n strings for locale en Feb 11 09:24:02 music volumio[25236]: Updating browse sources language Feb 11 09:24:02 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:02 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:02 music volumio[25236]: info: CoreCommandRouter::initPlayerControls Feb 11 09:24:02 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:02 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:03 music volumio[25236]: Express server listening on port 3000 Feb 11 09:24:03 music volumio[25236]: [Metrics] WebUI: 6s 586.02ms Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::resetVolumioState Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::getcurrentVolume Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: Volumio Network Manager: Network status updated: 1 Feb 11 09:24:03 music volumio-remote-updater[15329]: [2026-02-11 09:24:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770819839 101 Feb 11 09:24:03 music volumio[25309]: Forking 3 albumart workers Feb 11 09:24:03 music volumio[25236]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 09:24:03 music volumio[25236]: info: VolumeController:: Volume=86 Mute =false Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::pushState Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::updateTrackBlock Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrackBlock Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:24:03 music volumio[25236]: info: Reloading queue from file Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::setRepeat null single undefined Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::pushState Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::setRandom null Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::pushState Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:03 music volumio[25236]: info: Setting Device type: Raspberry PI Feb 11 09:24:03 music volumio[25236]: info: VolumeController:: Volume=86 Mute =false Feb 11 09:24:03 music volumio[25236]: info: CoreStateMachine::pushState Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:03 music volumio[25236]: info: Completed loading Core Plugins Feb 11 09:24:03 music volumio[25236]: info: Preparing to generate the ALSA configuration file Feb 11 09:24:03 music volumio[25236]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 11 09:24:03 music volumio[25236]: info: Discovery: Found device music Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:03 music volumio[25236]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 11 09:24:03 music volumio[25236]: info: Discovery: Found device music Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:03 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:03 music volumio[25236]: info: Asound.conf file unchanged, so no further update is needed Feb 11 09:24:03 music volumio[25236]: info: Output device has changed, restarting MPD Feb 11 09:24:03 music volumio[25236]: info: Output device has changed, restarting Shairport Sync Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:03 music volumio[25236]: info: ___________ START PLUGINS ___________ Feb 11 09:24:03 music sudo[25363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:24:03 music sudo[25363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:03 music volumio[25236]: info: ControllerMpd::onStart: Initializing MPD Feb 11 09:24:03 music volumio[25236]: info: Creating MPD Configuration file Feb 11 09:24:03 music sudo[25365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:24:03 music sudo[25363]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:03 music sudo[25365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:03 music volumio[25236]: info: [1770819843663] CoreMusicLibrary::Adding element Media Servers Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:03 music volumio[25236]: info: UPNP Browser: Client initialized successfully Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:03 music sudo[25375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:24:03 music sudo[25375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:03 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 09:24:03 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:03 music volumio[25236]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:03 music sudo[25373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:24:03 music sudo[25373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:03 music sudo[25373]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:03 music volumio[25236]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:03 music volumio[25236]: info: [1770819843791] CoreMusicLibrary::Adding element Last_100 Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:03 music volumio[25236]: info: [1770819843795] CoreMusicLibrary::Adding element Webradio Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:03 music volumio[25236]: info: Initializing BBC Radios Feb 11 09:24:03 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:03 music go-librespot[25381]: go-librespot daemon starting... Feb 11 09:24:03 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 09:24:03 music go-librespot[25390]: time="2026-02-11T09:24:03-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:03 music go-librespot[25390]: time="2026-02-11T09:24:03-05:00" level=debug msg="app state loaded" Feb 11 09:24:03 music systemd[1]: mpd.service: Deactivated successfully. Feb 11 09:24:03 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 09:24:03 music systemd[1]: mpd.service: Consumed 4.089s CPU time. Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:03 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:03 music go-librespot[25390]: time="2026-02-11T09:24:03-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:03 music systemd[1]: mpd.socket: Deactivated successfully. Feb 11 09:24:03 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 09:24:03 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 09:24:03 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 09:24:03 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 09:24:03 music volumio[25236]: info: Creating Spotify config file Feb 11 09:24:04 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:04 music sudo[25410]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 09:24:04 music sudo[25410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 09:24:04 music sudo[25410]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=info msg="zeroconf server listening on port 33345" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="obtained new client token: AAArkLcrn39CXmscXH/TFBT9qSWfTD0EqxafhcQbbyQDU+LTOqPJbjtgFdYDJW2jwkDFq2Epww4judAY6GcQrTRyjJxNlbqGHtPXtNXXg5rXL3Q6wg/UGdmGgm8ImS7zJ0PBkXOH0LcVeoWDuIx6uZrvDwwXGeWe4eLkj/NI3yxuu7C0PdJtluXchTo6QR01/fg55buDT8jG4618M1WnlmVZ97NwPOBbeBarcaEeCYR9XRMlTFOHDOs=" Feb 11 09:24:04 music volumio[25236]: info: Volumio Calling Home Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=debug msg="completed challenge" Feb 11 09:24:04 music go-librespot[25390]: time="2026-02-11T09:24:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:05 music volumio[25326]: Starting albumart workers Feb 11 09:24:05 music volumio[25324]: Starting albumart workers Feb 11 09:24:05 music volumio[25236]: info: MPD Permissions set Feb 11 09:24:05 music volumio[25236]: info: MPD Permissions set Feb 11 09:24:05 music volumio[25236]: info: Spotify config file written Feb 11 09:24:05 music go-librespot[25390]: time="2026-02-11T09:24:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:05 music sudo[25417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 09:24:05 music sudo[25417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:05 music go-librespot[25390]: time="2026-02-11T09:24:05-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:05 music go-librespot[25390]: time="2026-02-11T09:24:05-05:00" level=debug msg="completed challenge" Feb 11 09:24:05 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 09:24:05 music systemd[1]: go-librespot-daemon.service: Killing process 25396 (go-librespot) with signal SIGKILL. Feb 11 09:24:05 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 09:24:05 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:05 music volumio[25325]: Starting albumart workers Feb 11 09:24:05 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:05 music sudo[25417]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:05 music go-librespot[25419]: go-librespot daemon starting... Feb 11 09:24:05 music volumio[25236]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 09:24:05 music go-librespot[25420]: time="2026-02-11T09:24:05-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:05 music go-librespot[25420]: time="2026-02-11T09:24:05-05:00" level=debug msg="app state loaded" Feb 11 09:24:05 music volumio[25236]: info: Volumio called home Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:05 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:05 music go-librespot[25420]: time="2026-02-11T09:24:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:05 music volumio[25236]: info: No need to fix Spotify hosts Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=info msg="zeroconf server listening on port 44037" Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="obtained new client token: AAAUzp/7nPqQK7dDak2FiI/Xhv5Gkiw4exQjHqC0Aog9nytbBI7D4LkMjdIxxgo8KQpL6y7/SzM/TPQscdKN/2yAWzuteWZtSlaPmJFj+zNx6ykJq2BAES5Q7WrTyE5e43HOaixC7XsRvQSOKPuy+qLjGhEHO30BScWWGTO3I3XFclTYIyB63ZkzmXvgzwszAH0IEEoXCfOemTh5tWVl9K7D8Gu3+CFpl4GujwbTZsL/zJii5z31KRM=" Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:06 music volumio[25236]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=debug msg="completed challenge" Feb 11 09:24:06 music volumio[25236]: info: Starting Shairport Sync Feb 11 09:24:06 music volumio[25236]: info: Starting Shairport Sync Feb 11 09:24:06 music volumio[25236]: info: Starting Shairport Sync Feb 11 09:24:06 music go-librespot[25420]: time="2026-02-11T09:24:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:06 music sudo[25456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:06 music sudo[25456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:06 music volumio[25236]: info: Listing playlists Feb 11 09:24:06 music volumio[25236]: info: Listing playlists Feb 11 09:24:06 music sudo[25457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:06 music sudo[25457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:06 music sudo[25459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:06 music sudo[25459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:06 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 09:24:06 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 09:24:06 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:06 music systemd[1]: shairport-sync.service: Consumed 1.880s CPU time. Feb 11 09:24:06 music volumio[25236]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:06 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:06 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:06 music sudo[25456]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:06 music sudo[25457]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:06 music volumio[25236]: info: Shairport-Sync Started Feb 11 09:24:06 music volumio[25236]: Error adding Membership: Error: addMembership EINVAL Feb 11 09:24:06 music volumio[25236]: info: Shairport-Sync Started Feb 11 09:24:06 music sudo[25459]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:06 music volumio[25236]: info: Shairport-Sync Started Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=debug msg="completed challenge" Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:07 music go-librespot[25420]: time="2026-02-11T09:24:07-05:00" level=debug msg="completed challenge" Feb 11 09:24:08 music go-librespot[25420]: time="2026-02-11T09:24:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:08 music mpd[25412]: 2026-02-11T09:24:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 09:24:08 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 09:24:08 music sudo[25365]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:08 music sudo[25375]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:08 music volumio[25236]: info: Completed starting Core Plugins Feb 11 09:24:08 music volumio[25236]: info: ------------------------------------------- Feb 11 09:24:08 music volumio[25236]: info: ----- MyVolumio plugins startup ---- Feb 11 09:24:08 music volumio[25236]: info: ------------------------------------------- Feb 11 09:24:08 music volumio[25236]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 09:24:08 music volumio[25236]: error: MPD error: The expression evaluated to a falsy value: Feb 11 09:24:08 music volumio[25236]: assert.ok(self.idling) Feb 11 09:24:08 music volumio[25236]: error: The expression evaluated to a falsy value: Feb 11 09:24:08 music volumio[25236]: assert.ok(self.idling) Feb 11 09:24:08 music volumio[25236]: info: MPD running with PID25412 Feb 11 09:24:08 music volumio[25236]: ,establishing connection Feb 11 09:24:08 music volumio[25236]: error: updateQueue error: null Feb 11 09:24:08 music volumio[25236]: error: updateQueue error: null Feb 11 09:24:08 music go-librespot[25420]: time="2026-02-11T09:24:08-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 09:24:08 music go-librespot[25420]: time="2026-02-11T09:24:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:58448->104.199.241.202:4070: read: connection reset by peer" Feb 11 09:24:09 music sudo[25505]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:24:09 music sudo[25505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:09 music sudo[25505]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:09 music sudo[25507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:24:09 music sudo[25507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:09 music sudo[25507]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:09 music sudo[25509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 09:24:09 music sudo[25509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:09 music sudo[25509]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:09 music volumio[25236]: info: Upmpdcli Daemon Started Feb 11 09:24:09 music volumio[25236]: info: go-librespot daemon successfully initialized Feb 11 09:24:09 music go-librespot[25420]: time="2026-02-11T09:24:09-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 11 09:24:09 music go-librespot[25420]: time="2026-02-11T09:24:09-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:09 music go-librespot[25420]: time="2026-02-11T09:24:09-05:00" level=debug msg="completed challenge" Feb 11 09:24:09 music go-librespot[25420]: time="2026-02-11T09:24:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:10 music go-librespot[25420]: time="2026-02-11T09:24:10-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 11 09:24:10 music go-librespot[25420]: time="2026-02-11T09:24:10-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:10 music go-librespot[25420]: time="2026-02-11T09:24:10-05:00" level=debug msg="completed challenge" Feb 11 09:24:10 music go-librespot[25420]: time="2026-02-11T09:24:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:10 music go-librespot[25420]: time="2026-02-11T09:24:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:10 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:10 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:11 music sudo[25514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:24:11 music sudo[25514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:11 music sudo[25516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:24:11 music sudo[25516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:11 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 11 09:24:11 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 11 09:24:11 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 11 09:24:11 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 11 09:24:11 music sudo[25514]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:11 music sudo[25516]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:11 music mpd_monitor.sh[25519]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:24:11 music volumio[25236]: info: Successfully started MPD Monitor Feb 11 09:24:11 music volumio[25236]: info: Successfully started MPD Monitor Feb 11 09:24:12 music volumio[25236]: info: Initializing connection to go-librespot Websocket Feb 11 09:24:12 music volumio[25236]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 09:24:13 music volumio[25236]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 09:24:14 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 09:24:14 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:14 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:14 music go-librespot[25523]: go-librespot daemon starting... Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="app state loaded" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=info msg="zeroconf server listening on port 40209" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="obtained new client token: AAD+xetepUO/6ls3hx8QPOuKVMTIPH5HeKVu8bmzplLjfJCrJlWsD1DtHIkrHqMBy5HE5rxpltp8EDd7ymGcTsOtRR0OpwcJYDgoYOlaju9dqtJ1KJV6Ss1+BzYrDFDS44gt9oX6X0IggRifOXVpFS5JhT74ErWX2DhD5rW0463UyDdjcXre4luRelFqb4TDYtNBlFrqMpYlcqdUUwZa5h7blNQ9UTNlq1g5l8taQDouS+4oVjscsjI=" Feb 11 09:24:14 music volumio[25236]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:14 music volumio[25236]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=debug msg="completed challenge" Feb 11 09:24:14 music go-librespot[25524]: time="2026-02-11T09:24:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:15 music volumio[25236]: info: Initializing connection to go-librespot Websocket Feb 11 09:24:15 music go-librespot[25524]: time="2026-02-11T09:24:15-05:00" level=debug msg="new websocket client" Feb 11 09:24:15 music volumio[25236]: info: Connection to go-librespot Websocket established Feb 11 09:24:15 music go-librespot[25524]: time="2026-02-11T09:24:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:15 music go-librespot[25524]: time="2026-02-11T09:24:15-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:15 music go-librespot[25524]: time="2026-02-11T09:24:15-05:00" level=debug msg="completed challenge" Feb 11 09:24:15 music go-librespot[25524]: time="2026-02-11T09:24:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=debug msg="completed challenge" Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 09:24:16 music volumio[25236]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 09:24:16 music volumio[25236]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=debug msg="completed challenge" Feb 11 09:24:16 music go-librespot[25524]: time="2026-02-11T09:24:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:17 music go-librespot[25524]: time="2026-02-11T09:24:17-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 11 09:24:17 music go-librespot[25524]: time="2026-02-11T09:24:17-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:17 music go-librespot[25524]: time="2026-02-11T09:24:17-05:00" level=debug msg="completed challenge" Feb 11 09:24:17 music volumio[25236]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 09:24:17 music volumio[25236]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 09:24:17 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:17 music volumio[25236]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:17 music volumio[25236]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 09:24:17 music volumio[25236]: info: MyVolumio login type: Token Feb 11 09:24:17 music volumio[25236]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 09:24:17 music volumio[25236]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 09:24:17 music go-librespot[25524]: time="2026-02-11T09:24:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:18 music go-librespot[25524]: time="2026-02-11T09:24:18-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 11 09:24:18 music go-librespot[25524]: time="2026-02-11T09:24:18-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:18 music go-librespot[25524]: time="2026-02-11T09:24:18-05:00" level=debug msg="completed challenge" Feb 11 09:24:18 music volumio[25236]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 09:24:18 music volumio[25236]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 09:24:18 music volumio[25236]: info: Streaming services startup Feb 11 09:24:18 music volumio[25236]: info: Starting Streaming Daemon Feb 11 09:24:18 music go-librespot[25524]: time="2026-02-11T09:24:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:18 music go-librespot[25524]: time="2026-02-11T09:24:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:18 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:18 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:18 music volumio[25236]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 09:24:18 music sudo[25534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 09:24:18 music sudo[25534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:18 music sudo[25534]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:18 music volumio[25236]: info: Getting Spotify volume Feb 11 09:24:18 music volumio[25236]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:24:18 music volumio[25236]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 09:24:18 music volumio[25236]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 09:24:18 music volumio[25236]: errno: -111, Feb 11 09:24:18 music volumio[25236]: code: 'ECONNREFUSED', Feb 11 09:24:18 music volumio[25236]: syscall: 'connect', Feb 11 09:24:18 music volumio[25236]: address: '127.0.0.1', Feb 11 09:24:18 music volumio[25236]: port: 9879, Feb 11 09:24:18 music volumio[25236]: response: undefined Feb 11 09:24:18 music volumio[25236]: } Feb 11 09:24:18 music volumio[25236]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:24:19 music sudo[25569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 09:23' Feb 11 09:24:19 music sudo[25569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:19 music sudo[25569]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:19 music volumio-remote-updater[15329]: [2026-02-11 09:24:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 09:24:19 music volumio-remote-updater[15329]: [2026-02-11 09:24:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 09:24:19 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:19 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 09:24:19 music systemd[1]: volumio.service: Consumed 26.617s CPU time. Feb 11 09:24:20 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 09:24:20 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 09:24:20 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 55748. Feb 11 09:24:20 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 09:24:20 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 09:24:20 music systemd[1]: volumio.service: Consumed 26.617s CPU time. Feb 11 09:24:20 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 09:24:20 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 09:24:21 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 09:24:21 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:21 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:21 music go-librespot[25596]: go-librespot daemon starting... Feb 11 09:24:21 music go-librespot[25597]: time="2026-02-11T09:24:21-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:21 music go-librespot[25597]: time="2026-02-11T09:24:21-05:00" level=debug msg="app state loaded" Feb 11 09:24:21 music go-librespot[25597]: time="2026-02-11T09:24:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=info msg="zeroconf server listening on port 33709" Feb 11 09:24:22 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:22 music volumio[25581]: info: ----- Volumio3 ---- Feb 11 09:24:22 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:22 music volumio[25581]: info: ----- System startup ---- Feb 11 09:24:22 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="obtained new client token: AABs1UYsnoLZlfTN94T9FxqUaAp5Zes1Mu9GKmYaK1/aD/TUrqgQCCio2txuN6PDCVtfKXrXOB8wxl/r3ZUxgTUDiZf3lnhBeUb4+kE4IyCsf3C54lhK+pIF2tZAI5Qj4dBHs2KGQk8nuC8msklyiqrVkhiw8DbpVyt5LeWrVMaMJgnLzN2r4ocbiTy7zr7/LQBWgjezNYNBV1yY1cXKTbfrLWl7NP9fJITsJvn9Sm+pUWX2x96LKVk=" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=debug msg="completed challenge" Feb 11 09:24:22 music go-librespot[25597]: time="2026-02-11T09:24:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:23 music volumio[25581]: info: MYVOLUMIO Environment detected Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:23 music volumio[25581]: info: Plugin folders cleanup Feb 11 09:24:23 music volumio[25581]: info: Scanning into folder /volumio/app/plugins/ Feb 11 09:24:23 music volumio[25581]: info: Scanning category audio_interface Feb 11 09:24:23 music volumio[25581]: info: Scanning category miscellanea Feb 11 09:24:23 music volumio[25581]: info: Scanning category music_service Feb 11 09:24:23 music volumio[25581]: info: Scanning category plugins.json Feb 11 09:24:23 music volumio[25581]: info: Scanning category system_controller Feb 11 09:24:23 music volumio[25581]: info: Scanning category user_interface Feb 11 09:24:23 music volumio[25581]: info: Scanning into folder /data/plugins/ Feb 11 09:24:23 music volumio[25581]: info: Scanning category music_service Feb 11 09:24:23 music volumio[25581]: info: Plugin folders cleanup completed Feb 11 09:24:23 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:23 music volumio[25581]: info: ----- Core plugins startup ---- Feb 11 09:24:23 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:23 music volumio[25581]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 09:24:23 music volumio[25581]: info: Adding plugin upnp to MyMusic Plugins Feb 11 09:24:23 music volumio[25581]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=debug msg="completed challenge" Feb 11 09:24:23 music volumio[25581]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 09:24:23 music volumio[25581]: info: Loading plugins from folder /data/plugins/ Feb 11 09:24:23 music volumio[25581]: info: Loading plugin "system"... Feb 11 09:24:23 music volumio[25581]: info: Loading plugin "appearance"... Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:23 music go-librespot[25597]: time="2026-02-11T09:24:23-05:00" level=debug msg="completed challenge" Feb 11 09:24:24 music go-librespot[25597]: time="2026-02-11T09:24:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "network"... Feb 11 09:24:24 music volumio[25581]: info: Refreshing Cached IP Addresses Feb 11 09:24:24 music sudo[25619]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:24:24 music sudo[25619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:24 music sudo[25621]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:24:24 music sudo[25619]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:24 music sudo[25621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "services"... Feb 11 09:24:24 music sudo[25621]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "alsa_controller"... Feb 11 09:24:24 music sudo[25629]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 09:24:24 music sudo[25629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:24 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "wizard"... Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "networkfs"... Feb 11 09:24:24 music go-librespot[25597]: time="2026-02-11T09:24:24-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 11 09:24:24 music volumio[25581]: info: Starting Udev Watcher for removable devices Feb 11 09:24:24 music volumio[25581]: info: Ignoring mount for partition: boot Feb 11 09:24:24 music volumio[25581]: info: Ignoring mount for partition: volumio Feb 11 09:24:24 music volumio[25581]: info: Ignoring mount for partition: volumio_data Feb 11 09:24:24 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "volumio_command_line_client"... Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "upnp"... Feb 11 09:24:24 music volumio[25581]: info: [1770819864623] Starting Upmpd Daemon Feb 11 09:24:24 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "my_music"... Feb 11 09:24:24 music go-librespot[25597]: time="2026-02-11T09:24:24-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:24 music go-librespot[25597]: time="2026-02-11T09:24:24-05:00" level=debug msg="completed challenge" Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "mpd"... Feb 11 09:24:24 music go-librespot[25597]: time="2026-02-11T09:24:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:24 music volumio-remote-updater[15329]: [2026-02-11 09:24:24] [connect] Successful connection Feb 11 09:24:24 music volumio[25581]: info: Loading plugin "upnp_browser"... Feb 11 09:24:25 music sudo[25629]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:25 music go-librespot[25597]: time="2026-02-11T09:24:25-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 11 09:24:25 music go-librespot[25597]: time="2026-02-11T09:24:25-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 11 09:24:25 music go-librespot[25597]: time="2026-02-11T09:24:25-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:25 music go-librespot[25597]: time="2026-02-11T09:24:25-05:00" level=debug msg="completed challenge" Feb 11 09:24:25 music go-librespot[25597]: time="2026-02-11T09:24:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:26 music go-librespot[25597]: time="2026-02-11T09:24:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:26 music go-librespot[25597]: time="2026-02-11T09:24:26-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:26 music go-librespot[25597]: time="2026-02-11T09:24:26-05:00" level=debug msg="completed challenge" Feb 11 09:24:26 music volumio[25581]: info: Starting UPNP Browser Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "alarm-clock"... Feb 11 09:24:26 music go-librespot[25597]: time="2026-02-11T09:24:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:26 music go-librespot[25597]: time="2026-02-11T09:24:26-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:26 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:26 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "airplay_emulation"... Feb 11 09:24:26 music volumio[25581]: info: Starting Shairport Sync Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "last_100"... Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "webradio"... Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "i2s_dacs"... Feb 11 09:24:26 music volumio[25581]: info: I2S DAC not set, start Auto-detection Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "volumiodiscovery"... Feb 11 09:24:26 music volumio[25581]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:26 music volumio[25581]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:26 music volumio[25581]: *** WARNING *** For more information see Feb 11 09:24:26 music volumio[25581]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:26 music volumio[25581]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:26 music volumio[25581]: *** WARNING *** For more information see Feb 11 09:24:26 music node[25581]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:26 music node[25581]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:26 music node[25581]: *** WARNING *** For more information see Feb 11 09:24:26 music node[25581]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:26 music node[25581]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:26 music node[25581]: *** WARNING *** For more information see Feb 11 09:24:26 music volumio[25581]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 09:24:26 music volumio[25581]: info: Discovery: Started advertising with name: music Feb 11 09:24:26 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:26 music volumio[25581]: info: Loading plugin "spop"... Feb 11 09:24:27 music volumio[25581]: info: Loading plugin "outputs"... Feb 11 09:24:28 music volumio[25581]: info: Loading plugin "albumart"... Feb 11 09:24:28 music volumio[25581]: info: Plugin example_plugin is not enabled Feb 11 09:24:28 music volumio[25581]: info: Loading plugin "inputs"... Feb 11 09:24:28 music volumio[25581]: info: Loading plugin "updater_comm"... Feb 11 09:24:28 music volumio[25581]: info: Plugin mpdemulation is not enabled Feb 11 09:24:28 music volumio[25581]: info: Loading plugin "rest_api"... Feb 11 09:24:28 music volumio[25581]: info: Loading plugin "websocket"... Feb 11 09:24:28 music volumio[25581]: info: Starting Socket.io Server version 1.7.4 Feb 11 09:24:28 music volumio[25581]: info: Loading i18n strings for locale en Feb 11 09:24:28 music volumio[25581]: Updating browse sources language Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::initPlayerControls Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:28 music volumio[25581]: Express server listening on port 3000 Feb 11 09:24:28 music volumio[25581]: [Metrics] WebUI: 6s 595.09ms Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::resetVolumioState Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::getcurrentVolume Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: Volumio Network Manager: Network status updated: 1 Feb 11 09:24:28 music volumio[25581]: info: VolumeController:: Volume=86 Mute =false Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::pushState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::updateTrackBlock Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrackBlock Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25654]: Forking 3 albumart workers Feb 11 09:24:28 music volumio-remote-updater[15329]: [2026-02-11 09:24:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770819864 101 Feb 11 09:24:28 music volumio[25581]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 09:24:28 music volumio[25581]: info: Reloading queue from file Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::setRepeat null single undefined Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::pushState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::setRandom null Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::pushState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:28 music volumio[25581]: info: Setting Device type: Raspberry PI Feb 11 09:24:28 music volumio[25581]: info: Listing playlists Feb 11 09:24:28 music volumio[25581]: info: Listing playlists Feb 11 09:24:28 music volumio[25581]: info: VolumeController:: Volume=86 Mute =false Feb 11 09:24:28 music volumio[25581]: info: CoreStateMachine::pushState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:28 music volumio[25581]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 11 09:24:28 music volumio[25581]: info: Discovery: Found device music Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25581]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 11 09:24:28 music volumio[25581]: info: Discovery: Found device music Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:28 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:28 music volumio[25581]: info: Completed loading Core Plugins Feb 11 09:24:28 music volumio[25581]: info: Preparing to generate the ALSA configuration file Feb 11 09:24:28 music volumio[25581]: info: Asound.conf file unchanged, so no further update is needed Feb 11 09:24:28 music volumio[25581]: info: Output device has changed, restarting MPD Feb 11 09:24:28 music volumio[25581]: info: Output device has changed, restarting Shairport Sync Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:28 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:29 music sudo[25709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:24:29 music sudo[25709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:29 music sudo[25711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:24:29 music sudo[25711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:29 music sudo[25709]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:29 music volumio[25581]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:29 music volumio[25581]: info: ___________ START PLUGINS ___________ Feb 11 09:24:29 music volumio[25581]: info: ControllerMpd::onStart: Initializing MPD Feb 11 09:24:29 music volumio[25581]: info: Creating MPD Configuration file Feb 11 09:24:29 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:29 music volumio[25581]: info: [1770819869114] CoreMusicLibrary::Adding element Media Servers Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:29 music sudo[25721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:24:29 music sudo[25719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:24:29 music sudo[25719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:29 music sudo[25721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:29 music systemd[1]: mpd.service: Deactivated successfully. Feb 11 09:24:29 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 09:24:29 music systemd[1]: mpd.service: Consumed 4.215s CPU time. Feb 11 09:24:29 music systemd[1]: mpd.socket: Deactivated successfully. Feb 11 09:24:29 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 09:24:29 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 09:24:29 music sudo[25719]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:29 music volumio[25581]: info: UPNP Browser: Client initialized successfully Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:29 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 09:24:29 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 09:24:29 music volumio[25581]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:29 music systemd[1]: mpd.service: Deactivated successfully. Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:29 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 09:24:29 music systemd[1]: mpd.socket: Deactivated successfully. Feb 11 09:24:29 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 09:24:29 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 09:24:29 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 09:24:29 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 09:24:29 music volumio[25581]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:29 music volumio[25581]: info: [1770819869343] CoreMusicLibrary::Adding element Last_100 Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:29 music volumio[25581]: info: [1770819869353] CoreMusicLibrary::Adding element Webradio Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:29 music volumio[25581]: info: Initializing BBC Radios Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:29 music volumio[25581]: info: Creating Spotify config file Feb 11 09:24:29 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:29 music sudo[25735]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 09:24:29 music sudo[25735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 09:24:29 music sudo[25735]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:29 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 09:24:29 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:29 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:29 music go-librespot[25751]: go-librespot daemon starting... Feb 11 09:24:29 music go-librespot[25752]: time="2026-02-11T09:24:29-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:29 music volumio[25581]: info: Volumio Calling Home Feb 11 09:24:30 music go-librespot[25752]: time="2026-02-11T09:24:30-05:00" level=info msg="zeroconf server listening on port 40351" Feb 11 09:24:30 music volumio[25581]: info: MPD Permissions set Feb 11 09:24:30 music volumio[25581]: info: MPD Permissions set Feb 11 09:24:30 music volumio[25581]: info: Spotify config file written Feb 11 09:24:30 music volumio[25581]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 09:24:30 music volumio[25581]: info: Volumio called home Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music sudo[25765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 09:24:30 music sudo[25765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 09:24:30 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:30 music go-librespot[25774]: go-librespot daemon starting... Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:30 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:30 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:30 music volumio[25581]: info: No need to fix Spotify hosts Feb 11 09:24:30 music sudo[25765]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:30 music go-librespot[25778]: time="2026-02-11T09:24:30-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:30 music go-librespot[25778]: time="2026-02-11T09:24:30-05:00" level=debug msg="app state loaded" Feb 11 09:24:30 music go-librespot[25778]: time="2026-02-11T09:24:30-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:30 music volumio[25673]: Starting albumart workers Feb 11 09:24:30 music volumio[25672]: Starting albumart workers Feb 11 09:24:31 music volumio[25671]: Starting albumart workers Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=info msg="zeroconf server listening on port 40507" Feb 11 09:24:31 music volumio[25581]: info: Starting Shairport Sync Feb 11 09:24:31 music volumio[25581]: info: Starting Shairport Sync Feb 11 09:24:31 music volumio[25581]: info: Starting Shairport Sync Feb 11 09:24:31 music sudo[25792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:31 music sudo[25792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:31 music volumio[25581]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 11 09:24:31 music sudo[25790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="obtained new client token: AABiXIKKqjXe2CSpRa01mZo6YmfbFLh2tWQJqHAh7eM+C5i5EvyK7Irp8oFZBDXxeutNkKCdTHKnbaNpd1Jw6IdkmC6/wZ3ve+Sv4vAwj+OcGa6c/+O6GOuGEbAXbqSGkdHHFd5He/xvuzbbvOa2RC59yg8tnSp7ZMo+W46qNIeRtkePtQDUsvIVKw1zdvTEIGo0ucyNDxsH6ua0vY7iVvlXXFq+CxKH0YtdmFkTfQRAZe3gJVoVNlM=" Feb 11 09:24:31 music sudo[25790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:31 music sudo[25793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:31 music sudo[25793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:31 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 09:24:31 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 09:24:31 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:31 music systemd[1]: shairport-sync.service: Consumed 1.858s CPU time. Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=debug msg="completed challenge" Feb 11 09:24:31 music go-librespot[25778]: time="2026-02-11T09:24:31-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:31 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:31 music sudo[25792]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:31 music sudo[25793]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:31 music sudo[25790]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:31 music volumio[25581]: info: Shairport-Sync Started Feb 11 09:24:31 music volumio[25581]: Error adding Membership: Error: addMembership EINVAL Feb 11 09:24:31 music volumio[25581]: info: Shairport-Sync Started Feb 11 09:24:31 music volumio[25581]: info: Shairport-Sync Started Feb 11 09:24:31 music volumio[25581]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:32 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:32 music go-librespot[25778]: time="2026-02-11T09:24:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:32 music go-librespot[25778]: time="2026-02-11T09:24:32-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:32 music go-librespot[25778]: time="2026-02-11T09:24:32-05:00" level=debug msg="completed challenge" Feb 11 09:24:32 music go-librespot[25778]: time="2026-02-11T09:24:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:33 music go-librespot[25778]: time="2026-02-11T09:24:33-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 11 09:24:33 music go-librespot[25778]: time="2026-02-11T09:24:33-05:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 11 09:24:33 music go-librespot[25778]: time="2026-02-11T09:24:33-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 09:24:33 music go-librespot[25778]: time="2026-02-11T09:24:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:33900->104.199.241.202:443: read: connection reset by peer" Feb 11 09:24:33 music mpd[25750]: 2026-02-11T09:24:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 09:24:33 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 09:24:33 music sudo[25721]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:33 music sudo[25711]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:33 music volumio[25581]: info: Completed starting Core Plugins Feb 11 09:24:33 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:33 music volumio[25581]: info: ----- MyVolumio plugins startup ---- Feb 11 09:24:33 music volumio[25581]: info: ------------------------------------------- Feb 11 09:24:33 music volumio[25581]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 09:24:33 music volumio[25581]: error: MPD error: The expression evaluated to a falsy value: Feb 11 09:24:33 music volumio[25581]: assert.ok(self.idling) Feb 11 09:24:33 music volumio[25581]: error: The expression evaluated to a falsy value: Feb 11 09:24:33 music volumio[25581]: assert.ok(self.idling) Feb 11 09:24:33 music volumio[25581]: error: updateQueue error: null Feb 11 09:24:33 music volumio[25581]: info: MPD running with PID25750 Feb 11 09:24:33 music volumio[25581]: ,establishing connection Feb 11 09:24:33 music volumio[25581]: error: updateQueue error: null Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=debug msg="completed challenge" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:34 music volumio[25581]: info: go-librespot daemon successfully initialized Feb 11 09:24:34 music sudo[25853]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:24:34 music sudo[25853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:34 music sudo[25855]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:24:34 music sudo[25855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:34 music sudo[25853]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:34 music sudo[25855]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:34 music volumio[25581]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:34 music volumio[25581]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:34 music sudo[25857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 09:24:34 music sudo[25857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:34 music sudo[25857]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:34 music volumio[25581]: info: Upmpdcli Daemon Started Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=debug msg="completed challenge" Feb 11 09:24:34 music go-librespot[25778]: time="2026-02-11T09:24:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:35 music go-librespot[25778]: time="2026-02-11T09:24:35-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Feb 11 09:24:35 music go-librespot[25778]: time="2026-02-11T09:24:35-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 11 09:24:35 music go-librespot[25778]: time="2026-02-11T09:24:35-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:35 music go-librespot[25778]: time="2026-02-11T09:24:35-05:00" level=debug msg="completed challenge" Feb 11 09:24:35 music go-librespot[25778]: time="2026-02-11T09:24:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:35 music go-librespot[25778]: time="2026-02-11T09:24:35-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:35 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:35 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:36 music sudo[25862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:24:36 music sudo[25862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:36 music sudo[25864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:24:36 music sudo[25864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:36 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 11 09:24:36 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 11 09:24:36 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 11 09:24:36 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 11 09:24:36 music sudo[25864]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:36 music sudo[25862]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:36 music mpd_monitor.sh[25867]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:24:36 music volumio[25581]: info: Successfully started MPD Monitor Feb 11 09:24:36 music volumio[25581]: info: Successfully started MPD Monitor Feb 11 09:24:37 music volumio[25581]: info: Initializing connection to go-librespot Websocket Feb 11 09:24:37 music volumio[25581]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 09:24:38 music volumio[25581]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 09:24:38 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 09:24:38 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:38 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:38 music go-librespot[25871]: go-librespot daemon starting... Feb 11 09:24:38 music go-librespot[25872]: time="2026-02-11T09:24:38-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:38 music go-librespot[25872]: time="2026-02-11T09:24:38-05:00" level=debug msg="app state loaded" Feb 11 09:24:38 music go-librespot[25872]: time="2026-02-11T09:24:38-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=info msg="zeroconf server listening on port 45225" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="obtained new client token: AADJxjYyYsCPf12dI1SxEk/WE8oyVoiu2rXJG+YGA4IeF//OUiXYCmE+4sYL/IGM9qIo3xEoqGxQzMJ75VjUJzV3DZ8iwsJ8WMyfkBSvfufTiBbj6kotY4FTIi/fe83dSG0RAwwA+yC8SumEqWIUsRLIwTeEEOVDqiGAntYxtxNDeUulEYk52mvyQdEGWeqoCSocNLi2FrosTzw8900XIacMUybIm+RK4qiHoxYK9LSD68AuVLr0aF0=" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=debug msg="completed challenge" Feb 11 09:24:39 music go-librespot[25872]: time="2026-02-11T09:24:39-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="completed challenge" Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:40 music volumio[25581]: info: Initializing connection to go-librespot Websocket Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="new websocket client" Feb 11 09:24:40 music volumio[25581]: info: Connection to go-librespot Websocket established Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=debug msg="completed challenge" Feb 11 09:24:40 music go-librespot[25872]: time="2026-02-11T09:24:40-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:41 music go-librespot[25872]: time="2026-02-11T09:24:41-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 11 09:24:41 music go-librespot[25872]: time="2026-02-11T09:24:41-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:41 music go-librespot[25872]: time="2026-02-11T09:24:41-05:00" level=debug msg="completed challenge" Feb 11 09:24:41 music go-librespot[25872]: time="2026-02-11T09:24:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 09:24:41 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 09:24:42 music volumio[25581]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 09:24:42 music volumio[25581]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 09:24:42 music go-librespot[25872]: time="2026-02-11T09:24:42-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 09:24:42 music go-librespot[25872]: time="2026-02-11T09:24:42-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:42 music go-librespot[25872]: time="2026-02-11T09:24:42-05:00" level=debug msg="completed challenge" Feb 11 09:24:42 music go-librespot[25872]: time="2026-02-11T09:24:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:43 music volumio[25581]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 09:24:43 music volumio[25581]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 09:24:43 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:43 music volumio[25581]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:43 music volumio[25581]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 09:24:43 music volumio[25581]: info: MyVolumio login type: Token Feb 11 09:24:43 music volumio[25581]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 09:24:43 music volumio[25581]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 09:24:43 music go-librespot[25872]: time="2026-02-11T09:24:43-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 11 09:24:43 music go-librespot[25872]: time="2026-02-11T09:24:43-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:43 music go-librespot[25872]: time="2026-02-11T09:24:43-05:00" level=debug msg="completed challenge" Feb 11 09:24:43 music go-librespot[25872]: time="2026-02-11T09:24:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:43 music go-librespot[25872]: time="2026-02-11T09:24:43-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:43 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:43 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:44 music volumio[25581]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 09:24:44 music volumio[25581]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 09:24:44 music volumio[25581]: info: Streaming services startup Feb 11 09:24:44 music volumio[25581]: info: Starting Streaming Daemon Feb 11 09:24:44 music sudo[25882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 09:24:44 music sudo[25882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:44 music volumio[25581]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 09:24:44 music sudo[25882]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:44 music volumio[25581]: info: Getting Spotify volume Feb 11 09:24:44 music volumio[25581]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:24:44 music volumio[25581]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 09:24:44 music volumio[25581]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 09:24:44 music volumio[25581]: errno: -111, Feb 11 09:24:44 music volumio[25581]: code: 'ECONNREFUSED', Feb 11 09:24:44 music volumio[25581]: syscall: 'connect', Feb 11 09:24:44 music volumio[25581]: address: '127.0.0.1', Feb 11 09:24:44 music volumio[25581]: port: 9879, Feb 11 09:24:44 music volumio[25581]: response: undefined Feb 11 09:24:44 music volumio[25581]: } Feb 11 09:24:44 music volumio[25581]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:24:44 music sudo[25917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 09:23' Feb 11 09:24:44 music sudo[25917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:45 music sudo[25917]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:45 music volumio-remote-updater[15329]: [2026-02-11 09:24:45] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 09:24:45 music volumio-remote-updater[15329]: [2026-02-11 09:24:45] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 09:24:45 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:45 music systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 09:24:45 music systemd[1]: volumio.service: Consumed 26.525s CPU time. Feb 11 09:24:45 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 09:24:45 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 09:24:45 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 55749. Feb 11 09:24:45 music systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 09:24:45 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 09:24:45 music systemd[1]: volumio.service: Consumed 26.525s CPU time. Feb 11 09:24:45 music systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 09:24:45 music systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 09:24:46 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 09:24:46 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:46 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:46 music go-librespot[25944]: go-librespot daemon starting... Feb 11 09:24:46 music go-librespot[25945]: time="2026-02-11T09:24:46-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:46 music go-librespot[25945]: time="2026-02-11T09:24:46-05:00" level=debug msg="app state loaded" Feb 11 09:24:46 music go-librespot[25945]: time="2026-02-11T09:24:46-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=info msg="zeroconf server listening on port 43223" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="obtained new client token: AAAUFtOT3Ksa/h1lD1wShLGqqXZWktHUeShPxbeNHY/ik0Gzr8fVyRF1W4NeO1oI4eo4ypxQcUfg2h6uayGS7rDG+/X6kCtE+EKgj0B0hw+F1mbTeuyXnyQIHlW0W0X8OaT8lFSAHAtLebdrF/c/uRmCpMVIZg28UwW8FHJpach4m6XAHQYOQKXlVvnUnuSaigQmnNNZIZS4H8DfVdLy4hTpBrhLjQ32ucsnKcryoG4iCxXBee0KWbw=" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:47 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:47 music volumio[25929]: info: ----- Volumio3 ---- Feb 11 09:24:47 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:47 music volumio[25929]: info: ----- System startup ---- Feb 11 09:24:47 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=debug msg="completed challenge" Feb 11 09:24:47 music go-librespot[25945]: time="2026-02-11T09:24:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=debug msg="completed challenge" Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:48 music volumio[25929]: info: MYVOLUMIO Environment detected Feb 11 09:24:48 music volumio[25929]: info: Plugin folders cleanup Feb 11 09:24:48 music volumio[25929]: info: Scanning into folder /volumio/app/plugins/ Feb 11 09:24:48 music volumio[25929]: info: Scanning category audio_interface Feb 11 09:24:48 music volumio[25929]: info: Scanning category miscellanea Feb 11 09:24:48 music volumio[25929]: info: Scanning category music_service Feb 11 09:24:48 music volumio[25929]: info: Scanning category plugins.json Feb 11 09:24:48 music volumio[25929]: info: Scanning category system_controller Feb 11 09:24:48 music volumio[25929]: info: Scanning category user_interface Feb 11 09:24:48 music volumio[25929]: info: Scanning into folder /data/plugins/ Feb 11 09:24:48 music volumio[25929]: info: Scanning category music_service Feb 11 09:24:48 music volumio[25929]: info: Plugin folders cleanup completed Feb 11 09:24:48 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:48 music volumio[25929]: info: ----- Core plugins startup ---- Feb 11 09:24:48 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:48 music volumio[25929]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 09:24:48 music volumio[25929]: info: Adding plugin upnp to MyMusic Plugins Feb 11 09:24:48 music volumio[25929]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 09:24:48 music volumio[25929]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 09:24:48 music volumio[25929]: info: Loading plugins from folder /data/plugins/ Feb 11 09:24:48 music volumio[25929]: info: Loading plugin "system"... Feb 11 09:24:48 music volumio[25929]: info: Loading plugin "appearance"... Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:48 music go-librespot[25945]: time="2026-02-11T09:24:48-05:00" level=debug msg="completed challenge" Feb 11 09:24:49 music go-librespot[25945]: time="2026-02-11T09:24:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "network"... Feb 11 09:24:49 music volumio[25929]: info: Refreshing Cached IP Addresses Feb 11 09:24:49 music go-librespot[25945]: time="2026-02-11T09:24:49-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 11 09:24:49 music sudo[25967]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:24:49 music sudo[25967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:49 music sudo[25969]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:24:49 music sudo[25969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:49 music sudo[25967]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "services"... Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "alsa_controller"... Feb 11 09:24:49 music go-librespot[25945]: time="2026-02-11T09:24:49-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:49 music go-librespot[25945]: time="2026-02-11T09:24:49-05:00" level=debug msg="completed challenge" Feb 11 09:24:49 music sudo[25969]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:49 music sudo[25977]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 09:24:49 music sudo[25977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:49 music go-librespot[25945]: time="2026-02-11T09:24:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:49 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "wizard"... Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "networkfs"... Feb 11 09:24:49 music volumio[25929]: info: Starting Udev Watcher for removable devices Feb 11 09:24:49 music volumio[25929]: info: Ignoring mount for partition: boot Feb 11 09:24:49 music volumio[25929]: info: Ignoring mount for partition: volumio Feb 11 09:24:49 music volumio[25929]: info: Ignoring mount for partition: volumio_data Feb 11 09:24:49 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "volumio_command_line_client"... Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "upnp"... Feb 11 09:24:49 music volumio[25929]: info: [1770819889783] Starting Upmpd Daemon Feb 11 09:24:49 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "my_music"... Feb 11 09:24:49 music volumio[25929]: info: Loading plugin "mpd"... Feb 11 09:24:50 music volumio[25929]: info: Loading plugin "upnp_browser"... Feb 11 09:24:50 music sudo[25977]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:50 music volumio-remote-updater[15329]: [2026-02-11 09:24:50] [connect] Successful connection Feb 11 09:24:50 music go-librespot[25945]: time="2026-02-11T09:24:50-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 09:24:50 music go-librespot[25945]: time="2026-02-11T09:24:50-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:50 music go-librespot[25945]: time="2026-02-11T09:24:50-05:00" level=debug msg="completed challenge" Feb 11 09:24:50 music go-librespot[25945]: time="2026-02-11T09:24:50-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:51 music go-librespot[25945]: time="2026-02-11T09:24:51-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 11 09:24:51 music go-librespot[25945]: time="2026-02-11T09:24:51-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:51 music go-librespot[25945]: time="2026-02-11T09:24:51-05:00" level=debug msg="completed challenge" Feb 11 09:24:51 music go-librespot[25945]: time="2026-02-11T09:24:51-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:51 music go-librespot[25945]: time="2026-02-11T09:24:51-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:51 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:24:51 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:24:51 music volumio[25929]: info: Starting UPNP Browser Feb 11 09:24:51 music volumio[25929]: info: Loading plugin "alarm-clock"... Feb 11 09:24:51 music volumio[25929]: info: Loading plugin "airplay_emulation"... Feb 11 09:24:51 music volumio[25929]: info: Starting Shairport Sync Feb 11 09:24:51 music volumio[25929]: info: Loading plugin "last_100"... Feb 11 09:24:51 music volumio[25929]: info: Loading plugin "webradio"... Feb 11 09:24:52 music volumio[25929]: info: Loading plugin "i2s_dacs"... Feb 11 09:24:52 music volumio[25929]: info: I2S DAC not set, start Auto-detection Feb 11 09:24:52 music volumio[25929]: info: Loading plugin "volumiodiscovery"... Feb 11 09:24:52 music volumio[25929]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:52 music volumio[25929]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:52 music volumio[25929]: *** WARNING *** For more information see Feb 11 09:24:52 music volumio[25929]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:52 music volumio[25929]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:52 music volumio[25929]: *** WARNING *** For more information see Feb 11 09:24:52 music node[25929]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:52 music node[25929]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:52 music node[25929]: *** WARNING *** For more information see Feb 11 09:24:52 music node[25929]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:24:52 music node[25929]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:24:52 music node[25929]: *** WARNING *** For more information see Feb 11 09:24:52 music volumio[25929]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 09:24:52 music volumio[25929]: info: Discovery: Started advertising with name: music Feb 11 09:24:52 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:24:52 music volumio[25929]: info: Loading plugin "spop"... Feb 11 09:24:53 music volumio[25929]: info: Loading plugin "outputs"... Feb 11 09:24:53 music volumio[25929]: info: Loading plugin "albumart"... Feb 11 09:24:53 music volumio[25929]: info: Plugin example_plugin is not enabled Feb 11 09:24:53 music volumio[25929]: info: Loading plugin "inputs"... Feb 11 09:24:53 music volumio[25929]: info: Loading plugin "updater_comm"... Feb 11 09:24:53 music volumio[25929]: info: Plugin mpdemulation is not enabled Feb 11 09:24:53 music volumio[25929]: info: Loading plugin "rest_api"... Feb 11 09:24:53 music volumio[25929]: info: Loading plugin "websocket"... Feb 11 09:24:53 music volumio[25929]: info: Starting Socket.io Server version 1.7.4 Feb 11 09:24:53 music volumio[25929]: info: Loading i18n strings for locale en Feb 11 09:24:53 music volumio[25929]: Updating browse sources language Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::initPlayerControls Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:53 music volumio[25929]: Express server listening on port 3000 Feb 11 09:24:53 music volumio[25929]: [Metrics] WebUI: 6s 634.21ms Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::resetVolumioState Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::getcurrentVolume Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:53 music volumio[25929]: info: Volumio Network Manager: Network status updated: 1 Feb 11 09:24:53 music volumio-remote-updater[15329]: [2026-02-11 09:24:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770819890 101 Feb 11 09:24:53 music volumio[26002]: Forking 3 albumart workers Feb 11 09:24:53 music volumio[25929]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 09:24:53 music volumio[25929]: info: VolumeController:: Volume=86 Mute =false Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::pushState Feb 11 09:24:53 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::updateTrackBlock Feb 11 09:24:53 music volumio[25929]: info: CorePlayQueue::getTrackBlock Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:24:53 music volumio[25929]: info: Reloading queue from file Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::setRepeat null single undefined Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::pushState Feb 11 09:24:53 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::setRandom null Feb 11 09:24:53 music volumio[25929]: info: CoreStateMachine::pushState Feb 11 09:24:53 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:53 music volumio[25929]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:54 music volumio[25929]: info: Setting Device type: Raspberry PI Feb 11 09:24:54 music volumio[25929]: info: VolumeController:: Volume=86 Mute =false Feb 11 09:24:54 music volumio[25929]: info: CoreStateMachine::pushState Feb 11 09:24:54 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::volumioPushState Feb 11 09:24:54 music volumio[25929]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 11 09:24:54 music volumio[25929]: info: Discovery: Found device music Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:54 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:54 music volumio[25929]: info: Completed loading Core Plugins Feb 11 09:24:54 music volumio[25929]: info: Preparing to generate the ALSA configuration file Feb 11 09:24:54 music volumio[25929]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Feb 11 09:24:54 music volumio[25929]: info: Discovery: Found device music Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:54 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:54 music volumio[25929]: info: Asound.conf file unchanged, so no further update is needed Feb 11 09:24:54 music volumio[25929]: info: Output device has changed, restarting MPD Feb 11 09:24:54 music volumio[25929]: info: Output device has changed, restarting Shairport Sync Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:54 music sudo[26056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:24:54 music sudo[26056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:54 music volumio[25929]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:54 music sudo[26056]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:54 music volumio[25929]: info: ___________ START PLUGINS ___________ Feb 11 09:24:54 music sudo[26058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:24:54 music sudo[26058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:54 music volumio[25929]: info: ControllerMpd::onStart: Initializing MPD Feb 11 09:24:54 music volumio[25929]: info: Creating MPD Configuration file Feb 11 09:24:54 music systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:54 music volumio[25929]: info: [1770819894304] CoreMusicLibrary::Adding element Media Servers Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:54 music sudo[26066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:24:54 music sudo[26066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:54 music volumio[25929]: info: UPNP Browser: Client initialized successfully Feb 11 09:24:54 music systemd[1]: mpd.service: Deactivated successfully. Feb 11 09:24:54 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 09:24:54 music systemd[1]: mpd.service: Consumed 4.209s CPU time. Feb 11 09:24:54 music sudo[26066]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:54 music systemd[1]: mpd.socket: Deactivated successfully. Feb 11 09:24:54 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 09:24:54 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 09:24:54 music sudo[26068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:24:54 music sudo[26068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:54 music volumio[25929]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:54 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 09:24:54 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 09:24:54 music systemd[1]: mpd.service: Deactivated successfully. Feb 11 09:24:54 music systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 09:24:54 music volumio[25929]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:24:54 music systemd[1]: mpd.socket: Deactivated successfully. Feb 11 09:24:54 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 09:24:54 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:54 music volumio[25929]: info: [1770819894521] CoreMusicLibrary::Adding element Last_100 Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:54 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 09:24:54 music systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:24:54 music volumio[25929]: info: [1770819894538] CoreMusicLibrary::Adding element Webradio Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:54 music volumio[25929]: info: Initializing BBC Radios Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:54 music volumio[25929]: info: Creating Spotify config file Feb 11 09:24:54 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:54 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 09:24:54 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:54 music sudo[26082]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 09:24:54 music sudo[26082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 09:24:54 music sudo[26082]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:54 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:54 music go-librespot[26096]: go-librespot daemon starting... Feb 11 09:24:54 music go-librespot[26098]: time="2026-02-11T09:24:54-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:55 music go-librespot[26098]: time="2026-02-11T09:24:55-05:00" level=info msg="zeroconf server listening on port 46475" Feb 11 09:24:55 music volumio[25929]: info: Volumio Calling Home Feb 11 09:24:55 music volumio[26018]: Starting albumart workers Feb 11 09:24:55 music volumio[26019]: Starting albumart workers Feb 11 09:24:56 music volumio[26017]: Starting albumart workers Feb 11 09:24:56 music volumio[25929]: info: MPD Permissions set Feb 11 09:24:56 music volumio[25929]: info: MPD Permissions set Feb 11 09:24:56 music volumio[25929]: info: Volumio called home Feb 11 09:24:56 music volumio[25929]: info: Spotify config file written Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:56 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:56 music sudo[26112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 09:24:56 music sudo[26112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:56 music volumio[25929]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:56 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:24:56 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:24:56 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:24:56 music go-librespot[26121]: go-librespot daemon starting... Feb 11 09:24:56 music volumio[25929]: info: No need to fix Spotify hosts Feb 11 09:24:56 music sudo[26112]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:56 music go-librespot[26125]: time="2026-02-11T09:24:56-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:24:56 music go-librespot[26125]: time="2026-02-11T09:24:56-05:00" level=debug msg="app state loaded" Feb 11 09:24:56 music go-librespot[26125]: time="2026-02-11T09:24:56-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=info msg="zeroconf server listening on port 34407" Feb 11 09:24:57 music volumio[25929]: info: Listing playlists Feb 11 09:24:57 music volumio[25929]: info: Listing playlists Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="obtained new client token: AACxeC7u0jvkQmx/VsZJAgTqqlOe/q6SSC7IRAZnTnBnj2hjqIfZ/OUYbROra3IYT/+ya+N9ST2fvF5Zocfav9/qSJFGS+dJIL7ceLMqz5lAz+1TbpNAD+iGvppJmpWLP5LnKYO/tLN1uCs5qpkTAhxVGxgdIdGIR6jSNwsztWKKaWVr+J20pwStu3FKcEZeARxsxLDeL8xJNPkyVyDkwneLDIIlSD5H9kkSAbwgcetaLLPiWHDS" Feb 11 09:24:57 music volumio[25929]: info: Starting Shairport Sync Feb 11 09:24:57 music volumio[25929]: info: Starting Shairport Sync Feb 11 09:24:57 music volumio[25929]: info: Starting Shairport Sync Feb 11 09:24:57 music sudo[26149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:57 music sudo[26149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:57 music volumio[25929]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 11 09:24:57 music sudo[26151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:57 music sudo[26151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:57 music sudo[26153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:24:57 music sudo[26153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:24:57 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 09:24:57 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 09:24:57 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:57 music systemd[1]: shairport-sync.service: Consumed 1.770s CPU time. Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=debug msg="completed challenge" Feb 11 09:24:57 music volumio[25929]: info: CoreCommandRouter::volumioGetState Feb 11 09:24:57 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:24:57 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:57 music go-librespot[26125]: time="2026-02-11T09:24:57-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:57 music sudo[26149]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:57 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 09:24:57 music systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 09:24:57 music volumio[25929]: info: Shairport-Sync Started Feb 11 09:24:57 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:57 music volumio[25929]: Error adding Membership: Error: addMembership EINVAL Feb 11 09:24:57 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 09:24:57 music sudo[26151]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:57 music sudo[26153]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:57 music volumio[25929]: info: Shairport-Sync Started Feb 11 09:24:57 music volumio[25929]: info: Shairport-Sync Started Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=debug msg="completed challenge" Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=debug msg="completed challenge" Feb 11 09:24:58 music go-librespot[26125]: time="2026-02-11T09:24:58-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:24:58 music mpd[26099]: 2026-02-11T09:24:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 09:24:58 music systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 09:24:58 music sudo[26068]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:58 music sudo[26058]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:58 music volumio[25929]: info: Completed starting Core Plugins Feb 11 09:24:58 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:58 music volumio[25929]: info: ----- MyVolumio plugins startup ---- Feb 11 09:24:58 music volumio[25929]: info: ------------------------------------------- Feb 11 09:24:58 music volumio[25929]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 09:24:59 music volumio[25929]: error: MPD error: The expression evaluated to a falsy value: Feb 11 09:24:59 music volumio[25929]: assert.ok(self.idling) Feb 11 09:24:59 music volumio[25929]: error: The expression evaluated to a falsy value: Feb 11 09:24:59 music volumio[25929]: assert.ok(self.idling) Feb 11 09:24:59 music volumio[25929]: error: updateQueue error: null Feb 11 09:24:59 music volumio[25929]: info: MPD running with PID26099 Feb 11 09:24:59 music volumio[25929]: ,establishing connection Feb 11 09:24:59 music volumio[25929]: error: updateQueue error: null Feb 11 09:24:59 music go-librespot[26125]: time="2026-02-11T09:24:59-05:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 11 09:24:59 music go-librespot[26125]: time="2026-02-11T09:24:59-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 09:24:59 music sudo[26200]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:24:59 music sudo[26200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:59 music go-librespot[26125]: time="2026-02-11T09:24:59-05:00" level=debug msg="completed keyexchange" Feb 11 09:24:59 music go-librespot[26125]: time="2026-02-11T09:24:59-05:00" level=debug msg="completed challenge" Feb 11 09:24:59 music sudo[26200]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:59 music sudo[26202]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:24:59 music sudo[26202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:59 music sudo[26202]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:59 music sudo[26205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 09:24:59 music sudo[26205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:24:59 music sudo[26205]: pam_unix(sudo:session): session closed for user root Feb 11 09:24:59 music volumio[25929]: info: Upmpdcli Daemon Started Feb 11 09:25:00 music go-librespot[26125]: time="2026-02-11T09:25:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:00 music volumio[25929]: info: go-librespot daemon successfully initialized Feb 11 09:25:00 music go-librespot[26125]: time="2026-02-11T09:25:00-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 11 09:25:00 music go-librespot[26125]: time="2026-02-11T09:25:00-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:00 music go-librespot[26125]: time="2026-02-11T09:25:00-05:00" level=debug msg="completed challenge" Feb 11 09:25:00 music go-librespot[26125]: time="2026-02-11T09:25:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:01 music go-librespot[26125]: time="2026-02-11T09:25:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:25:01 music go-librespot[26125]: time="2026-02-11T09:25:01-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:01 music go-librespot[26125]: time="2026-02-11T09:25:01-05:00" level=debug msg="completed challenge" Feb 11 09:25:01 music go-librespot[26125]: time="2026-02-11T09:25:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:01 music go-librespot[26125]: time="2026-02-11T09:25:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:01 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:25:01 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:25:02 music sudo[26209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:25:02 music sudo[26209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:25:02 music sudo[26212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:25:02 music sudo[26212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:25:02 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 11 09:25:02 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 11 09:25:02 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 11 09:25:02 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 11 09:25:02 music sudo[26209]: pam_unix(sudo:session): session closed for user root Feb 11 09:25:02 music mpd_monitor.sh[26214]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:25:02 music volumio[25929]: info: Successfully started MPD Monitor Feb 11 09:25:02 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 11 09:25:02 music systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 11 09:25:02 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 11 09:25:02 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 11 09:25:02 music sudo[26212]: pam_unix(sudo:session): session closed for user root Feb 11 09:25:02 music mpd_monitor.sh[26217]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:25:02 music volumio[25929]: info: Successfully started MPD Monitor Feb 11 09:25:03 music volumio[25929]: info: Initializing connection to go-librespot Websocket Feb 11 09:25:03 music volumio[25929]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 09:25:04 music volumio[25929]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 09:25:04 music volumio[25929]: info: CoreCommandRouter::volumioGetState Feb 11 09:25:04 music volumio[25929]: info: CorePlayQueue::getTrack 0 Feb 11 09:25:04 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 09:25:04 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:25:04 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 09:25:04 music go-librespot[26221]: go-librespot daemon starting... Feb 11 09:25:04 music go-librespot[26222]: time="2026-02-11T09:25:04-05:00" level=info msg="running go-librespot 0.6.2" Feb 11 09:25:04 music go-librespot[26222]: time="2026-02-11T09:25:04-05:00" level=debug msg="app state loaded" Feb 11 09:25:04 music go-librespot[26222]: time="2026-02-11T09:25:04-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=info msg="zeroconf server listening on port 44839" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="obtained new client token: AACdQhhiu2JJc6OhyOW/szkyYFASwQoh9xp1GbNiODqTivUk9uoMzexRTBMKmPT6huSljhQw3myt65eOCVHUJAdWENP/tHMkqOAzeELksalzrObN/JXx+V0bYvejSDgdn6dK2a4e3c6T8TF3+Jd3xcr7DBYViAdniJ6gCB5TAcWuutxWCMz9iKEPWkfIgP/XoKS1H7VNFuPlozShjCzjrLpSEXMrdNi5vtSIXpBnywzUWAZbJvTFavY=" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=debug msg="completed challenge" Feb 11 09:25:05 music go-librespot[26222]: time="2026-02-11T09:25:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="completed challenge" Feb 11 09:25:06 music volumio[25929]: info: Initializing connection to go-librespot Websocket Feb 11 09:25:06 music volumio[25929]: info: Connection to go-librespot Websocket established Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="new websocket client" Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=debug msg="completed challenge" Feb 11 09:25:06 music go-librespot[26222]: time="2026-02-11T09:25:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 09:25:07 music volumio[25929]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 09:25:07 music volumio[25929]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 09:25:07 music go-librespot[26222]: time="2026-02-11T09:25:07-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 11 09:25:07 music go-librespot[26222]: time="2026-02-11T09:25:07-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:07 music go-librespot[26222]: time="2026-02-11T09:25:07-05:00" level=debug msg="completed challenge" Feb 11 09:25:07 music go-librespot[26222]: time="2026-02-11T09:25:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:08 music go-librespot[26222]: time="2026-02-11T09:25:08-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 09:25:08 music volumio[25929]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 09:25:08 music volumio[25929]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 09:25:08 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:25:08 music volumio[25929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:25:08 music volumio[25929]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 09:25:08 music volumio[25929]: info: MyVolumio login type: Token Feb 11 09:25:08 music volumio[25929]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 09:25:08 music volumio[25929]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 09:25:08 music go-librespot[26222]: time="2026-02-11T09:25:08-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:08 music go-librespot[26222]: time="2026-02-11T09:25:08-05:00" level=debug msg="completed challenge" Feb 11 09:25:08 music go-librespot[26222]: time="2026-02-11T09:25:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:09 music go-librespot[26222]: time="2026-02-11T09:25:09-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 11 09:25:09 music volumio[25929]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 09:25:09 music volumio[25929]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 09:25:09 music volumio[25929]: info: Streaming services startup Feb 11 09:25:09 music volumio[25929]: info: Starting Streaming Daemon Feb 11 09:25:09 music sudo[26232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 09:25:09 music sudo[26232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 09:25:09 music volumio[25929]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 09:25:09 music go-librespot[26222]: time="2026-02-11T09:25:09-05:00" level=debug msg="completed keyexchange" Feb 11 09:25:09 music go-librespot[26222]: time="2026-02-11T09:25:09-05:00" level=debug msg="completed challenge" Feb 11 09:25:09 music sudo[26232]: pam_unix(sudo:session): session closed for user root Feb 11 09:25:09 music volumio[25929]: info: Getting Spotify volume Feb 11 09:25:09 music volumio[25929]: error: Cannot start Volumio Streaming Daemon Feb 11 09:25:09 music volumio[25929]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 09:25:09 music volumio[25929]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 09:25:09 music volumio[25929]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 11 09:25:09 music go-librespot[26222]: time="2026-02-11T09:25:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:09 music go-librespot[26222]: time="2026-02-11T09:25:09-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 09:25:09 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 09:25:09 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 09:25:09 music volumio[25929]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:25:09 music volumio[25929]: Error: socket hang up Feb 11 09:25:09 music volumio[25929]: at connResetException (node:internal/errors:720:14) Feb 11 09:25:09 music volumio[25929]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 09:25:09 music volumio[25929]: at Socket.emit (node:events:526:35) Feb 11 09:25:09 music volumio[25929]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 09:25:09 music volumio[25929]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 09:25:09 music volumio[25929]: code: 'ECONNRESET', Feb 11 09:25:09 music volumio[25929]: response: undefined Feb 11 09:25:09 music volumio[25929]: } Feb 11 09:25:09 music volumio[25929]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:25:10 music sudo[26266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 09:24' Feb 11 09:25:10 music sudo[26266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"