Feb 07 03:35:00 volumio-stefan go-librespot[9483]: time="2026-02-07T03:35:00+02:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Feb 07 03:35:00 volumio-stefan go-librespot[9483]: time="2026-02-07T03:35:00+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:00 volumio-stefan volumio[9467]: info: Applying required configuration parameters for plugin backup_restore Feb 07 03:35:00 volumio-stefan volumio[9467]: info: Loading plugin "Systeminfo"... Feb 07 03:35:00 volumio-stefan go-librespot[9483]: time="2026-02-07T03:35:00+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:00 volumio-stefan go-librespot[9483]: time="2026-02-07T03:35:00+02:00" level=debug msg="completed challenge" Feb 07 03:35:00 volumio-stefan go-librespot[9483]: time="2026-02-07T03:35:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:00 volumio-stefan go-librespot[9483]: time="2026-02-07T03:35:00+02: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 07 03:35:00 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:00 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:35:00 volumio-stefan volumio[9538]: Forking 3 albumart workers Feb 07 03:35:00 volumio-stefan volumio[9467]: info: Loading i18n strings for locale en Feb 07 03:35:00 volumio-stefan volumio[9467]: Updating browse sources language Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:00 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25125. Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:35:00 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::initPlayerControls Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:35:00 volumio-stefan volumio[9467]: Express server listening on port 3000 Feb 07 03:35:00 volumio-stefan volumio[9467]: [Metrics] WebUI: 7s 409.87ms Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreStateMachine::resetVolumioState Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreStateMachine::getcurrentVolume Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreStateMachine::pushState Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:35:00 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:00 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:00 volumio-stefan upmpdcli[9578]: Could not open config: /tmp/upmpdcli.conf Feb 07 03:35:00 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:00 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 03:35:00 volumio-stefan volumio[9467]: info: Volumio Network Manager: Network status updated: 2 Feb 07 03:35:01 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770428096 101 Feb 07 03:35:01 volumio-stefan volumio[9467]: 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 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Reloading queue from file Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreStateMachine::setRepeat null single undefined Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreStateMachine::pushState Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreStateMachine::setRandom null Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreStateMachine::pushState Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Setting Device type: Raspberry PI Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Completed loading Core Plugins Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Preparing to generate the ALSA configuration file Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Asound.conf file unchanged, so no further update is needed Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Output device has changed, restarting MPD Feb 07 03:35:01 volumio-stefan volumio[9467]: info: ___________ START PLUGINS ___________ Feb 07 03:35:01 volumio-stefan volumio[9467]: info: ControllerMpd::onStart: Initializing MPD Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Creating MPD Configuration file Feb 07 03:35:01 volumio-stefan sudo[9589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:35:01 volumio-stefan sudo[9589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:35:01 volumio-stefan sudo[9589]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:01 volumio-stefan volumio[9467]: info: [1770428101317] CoreMusicLibrary::Adding element Last_100 Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:01 volumio-stefan sudo[9591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:35:01 volumio-stefan volumio[9467]: info: [1770428101331] CoreMusicLibrary::Adding element Webradio Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:01 volumio-stefan sudo[9591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:01 volumio-stefan sudo[9593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:35:01 volumio-stefan sudo[9593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:01 volumio-stefan sudo[9595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:35:01 volumio-stefan sudo[9595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Initializing BBC Radios Feb 07 03:35:01 volumio-stefan sudo[9593]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:01 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 03:35:01 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 03:35:01 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 03:35:01 volumio-stefan systemd[1]: mpd.service: Consumed 3.299s CPU time. Feb 07 03:35:01 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 03:35:01 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 03:35:01 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Creating Spotify config file Feb 07 03:35:01 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:01 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 03:35:01 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 03:35:01 volumio-stefan volumio[9550]: Starting albumart workers Feb 07 03:35:01 volumio-stefan sudo[9614]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 03:35:01 volumio-stefan sudo[9614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 03:35:01 volumio-stefan sudo[9614]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:01 volumio-stefan volumio[9467]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 03:35:01 volumio-stefan volumio[9548]: Starting albumart workers Feb 07 03:35:01 volumio-stefan volumio[9549]: Starting albumart workers Feb 07 03:35:01 volumio-stefan volumio[9467]: info: Volumio Calling Home Feb 07 03:35:02 volumio-stefan volumio[9467]: info: [now-playing] App is listening on port 4004. Feb 07 03:35:02 volumio-stefan volumio[9467]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 03:35:02 volumio-stefan volumio[9467]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:35:02 volumio-stefan volumio[9467]: info: Discovery: Found device Volumio Stefan Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:02 volumio-stefan volumio[9467]: info: MPD Permissions set Feb 07 03:35:02 volumio-stefan volumio[9467]: info: MPD Permissions set Feb 07 03:35:02 volumio-stefan volumio[9467]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:35:02 volumio-stefan volumio[9467]: info: Discovery: Found device Volumio Stefan Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:02 volumio-stefan volumio[9467]: info: Spotify config file written Feb 07 03:35:02 volumio-stefan volumio[9467]: 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 07 03:35:02 volumio-stefan volumio[9467]: info: Volumio called home Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:02 volumio-stefan sudo[9634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 03:35:02 volumio-stefan sudo[9634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:02 volumio-stefan volumio[9467]: info: No need to fix Spotify hosts Feb 07 03:35:03 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:03 volumio-stefan go-librespot[9643]: go-librespot daemon starting... Feb 07 03:35:03 volumio-stefan sudo[9634]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=debug msg="app state loaded" Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:35:03 volumio-stefan volumio[9467]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 03:35:03 volumio-stefan volumio[9467]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:03 volumio-stefan volumio[9467]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=info msg="zeroconf server listening on port 41027" Feb 07 03:35:03 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:03+02:00" level=debug msg="obtained new client token: AADmobeBbPOGYM4cM7A0y3eHgYjBONwHPeY6L4mo3r0AFXLgM4LTV4CnUQ+/IK1mrB/WSRiHBG/lRFSjiwlxcdgroP8hKsyHJTlAspdAlL+Wehk9/yETnXB9Jzm97EPk2wz0fuQR8XPCzgEAuTxgPX1eTgTw7Dndvps7BF2GRfSfhROqZuHyJyIDlkxzY21ym/aAiK5ucX+EHgr+FJ6iHtn4UHETl0IeNsiuYeu6qfYJX069Faq14L0=" Feb 07 03:35:04 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:04+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:04 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:04+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:04 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:04+02:00" level=debug msg="completed challenge" Feb 07 03:35:04 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:04+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:05 volumio-stefan mpd[9616]: 2026-02-07T03:35:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 03:35:05 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 03:35:05 volumio-stefan sudo[9591]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:05 volumio-stefan sudo[9595]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:05 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:35:05 volumio-stefan volumio[9467]: info: Completed starting Core Plugins Feb 07 03:35:05 volumio-stefan volumio[9467]: info: ------------------------------------------- Feb 07 03:35:05 volumio-stefan volumio[9467]: info: ----- MyVolumio plugins startup ---- Feb 07 03:35:05 volumio-stefan volumio[9467]: info: ------------------------------------------- Feb 07 03:35:05 volumio-stefan volumio[9467]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 03:35:05 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:05+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:05 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:05+02:00" level=debug msg="completed challenge" Feb 07 03:35:05 volumio-stefan volumio[9467]: error: MPD error: The expression evaluated to a falsy value: Feb 07 03:35:05 volumio-stefan volumio[9467]: assert.ok(self.idling) Feb 07 03:35:05 volumio-stefan volumio[9467]: error: The expression evaluated to a falsy value: Feb 07 03:35:05 volumio-stefan volumio[9467]: assert.ok(self.idling) Feb 07 03:35:05 volumio-stefan volumio[9467]: error: updateQueue error: null Feb 07 03:35:05 volumio-stefan volumio[9467]: info: MPD running with PID9616 Feb 07 03:35:05 volumio-stefan volumio[9467]: ,establishing connection Feb 07 03:35:05 volumio-stefan volumio[9467]: error: updateQueue error: null Feb 07 03:35:05 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:05+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:05 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:35:06 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:06+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:06 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:06+02:00" level=debug msg="completed challenge" Feb 07 03:35:06 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:06 volumio-stefan volumio[9467]: info: go-librespot daemon successfully initialized Feb 07 03:35:06 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:06+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 03:35:07 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:07+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:07 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:07+02:00" level=debug msg="completed challenge" Feb 07 03:35:07 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:07+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:08 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 03:35:08 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:08+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:08 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:08+02:00" level=debug msg="completed challenge" Feb 07 03:35:08 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:09 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:09+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 03:35:09 volumio-stefan volumio[9467]: info: Initializing connection to go-librespot Websocket Feb 07 03:35:09 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:09+02:00" level=debug msg="new websocket client" Feb 07 03:35:09 volumio-stefan volumio[9467]: info: Connection to go-librespot Websocket established Feb 07 03:35:09 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:09+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:09 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:09+02:00" level=debug msg="completed challenge" Feb 07 03:35:10 volumio-stefan volumio[9467]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 03:35:10 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:10+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:10 volumio-stefan go-librespot[9647]: time="2026-02-07T03:35:10+02: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 07 03:35:10 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:10 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:35:10 volumio-stefan volumio[9467]: info: Connection to go-librespot Websocket closed Feb 07 03:35:12 volumio-stefan volumio[9467]: info: Getting Spotify volume Feb 07 03:35:12 volumio-stefan volumio[9467]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:35:12 volumio-stefan volumio[9467]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 03:35:12 volumio-stefan volumio[9467]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 03:35:12 volumio-stefan volumio[9467]: errno: -111, Feb 07 03:35:12 volumio-stefan volumio[9467]: code: 'ECONNREFUSED', Feb 07 03:35:12 volumio-stefan volumio[9467]: syscall: 'connect', Feb 07 03:35:12 volumio-stefan volumio[9467]: address: '127.0.0.1', Feb 07 03:35:12 volumio-stefan volumio[9467]: port: 9879, Feb 07 03:35:12 volumio-stefan volumio[9467]: response: undefined Feb 07 03:35:12 volumio-stefan volumio[9467]: } Feb 07 03:35:12 volumio-stefan volumio[9467]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:35:12 volumio-stefan sudo[9695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 03:34' Feb 07 03:35:12 volumio-stefan sudo[9695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:13 volumio-stefan sudo[9695]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:13 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 03:35:13 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:13 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:13 volumio-stefan go-librespot[9703]: go-librespot daemon starting... Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=debug msg="app state loaded" Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 03:35:13 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:13+02:00" level=info msg="zeroconf server listening on port 33553" Feb 07 03:35:13 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 03:35:13 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 03:35:13 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:13 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 03:35:13 volumio-stefan systemd[1]: volumio.service: Consumed 21.939s CPU time. Feb 07 03:35:13 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 03:35:13 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 03:35:14 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:14+02:00" level=debug msg="obtained new client token: AAAbRMliLtcLfVS4aJSxE7fuCnTQ76bSTlNTBGxDrqFSxp19kmg0KdFitR3a47vBU4/Cf2Njx/kOnCvQ8iVLaqCYI2b/89BxvkzloQ31XHAoOtctOr7tuoREW1+wvgtTcphPru3ZBQ1E7kvpK+gGqQ7BP2o6VMTOMJ0ztFDUxPfMjtPcCGS20nzycH+7o5e6m86nIfbK3zh0F3OT/sdCkTFbzHRFC/ovHfNPnu4D/MIyjguDQ3v/cWo=" Feb 07 03:35:14 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:14 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:14+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:14 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:14+02:00" level=debug msg="completed challenge" Feb 07 03:35:14 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8110. Feb 07 03:35:14 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:14 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 03:35:14 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 03:35:14 volumio-stefan systemd[1]: volumio.service: Consumed 21.939s CPU time. Feb 07 03:35:14 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 03:35:14 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 03:35:14 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:14+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Feb 07 03:35:15 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:15+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Feb 07 03:35:15 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:15+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 03:35:15 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:15+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:15 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:15+02:00" level=debug msg="completed challenge" Feb 07 03:35:15 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:15+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:15 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25126. Feb 07 03:35:15 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:16 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ----- Volumio3 ---- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ----- System startup ---- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:16 volumio-stefan upmpdcli[9742]: Could not open config: /tmp/upmpdcli.conf Feb 07 03:35:16 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:16 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 03:35:16 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:16+02:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Feb 07 03:35:16 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 03:35:16 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:16+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:16 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:16+02:00" level=debug msg="completed challenge" Feb 07 03:35:16 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:16 volumio-stefan volumio[9721]: info: MYVOLUMIO Environment detected Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Plugin folders cleanup Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning into folder /volumio/app/plugins/ Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category audio_interface Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category miscellanea Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category music_service Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category plugins.json Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category system_controller Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category user_interface Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning into folder /data/plugins/ Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category music_service Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category system_controller Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Scanning category user_interface Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Plugin folders cleanup completed Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ----- Core plugins startup ---- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Adding plugin upnp to MyMusic Plugins Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Loading plugins from folder /data/plugins/ Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Loading plugin "system"... Feb 07 03:35:16 volumio-stefan volumio[9721]: info: Loading plugin "appearance"... Feb 07 03:35:17 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:17 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:17+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:17 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:17+02:00" level=debug msg="completed challenge" Feb 07 03:35:17 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:17 volumio-stefan volumio[9721]: info: Loading plugin "network"... Feb 07 03:35:17 volumio-stefan volumio[9721]: info: Refreshing Cached IP Addresses Feb 07 03:35:17 volumio-stefan sudo[9751]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 03:35:17 volumio-stefan sudo[9753]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 03:35:17 volumio-stefan sudo[9753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:17 volumio-stefan sudo[9751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:17 volumio-stefan sudo[9753]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:17 volumio-stefan volumio[9721]: info: Loading plugin "services"... Feb 07 03:35:17 volumio-stefan sudo[9751]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:17 volumio-stefan volumio[9721]: info: Loading plugin "alsa_controller"... Feb 07 03:35:17 volumio-stefan sudo[9761]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 03:35:17 volumio-stefan sudo[9761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:17 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:17 volumio-stefan volumio[9721]: info: Loading plugin "wizard"... Feb 07 03:35:17 volumio-stefan volumio[9721]: info: Loading plugin "networkfs"... Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Starting Udev Watcher for removable devices Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Ignoring mount for partition: boot Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Ignoring mount for partition: volumio Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Ignoring mount for partition: volumio_data Feb 07 03:35:18 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Loading plugin "volumio_command_line_client"... Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Plugin upnp is not enabled Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Loading plugin "my_music"... Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Loading plugin "mpd"... Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Plugin upnp_browser is not enabled Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Loading plugin "alarm-clock"... Feb 07 03:35:18 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:18+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Plugin airplay_emulation is not enabled Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Loading plugin "last_100"... Feb 07 03:35:18 volumio-stefan volumio[9721]: info: Loading plugin "webradio"... Feb 07 03:35:18 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:18] [connect] Successful connection Feb 07 03:35:18 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:18+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:18 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:18+02:00" level=debug msg="completed challenge" Feb 07 03:35:19 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:19+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:19 volumio-stefan volumio[9721]: info: Loading plugin "i2s_dacs"... Feb 07 03:35:19 volumio-stefan volumio[9721]: info: Loading plugin "volumiodiscovery"... Feb 07 03:35:19 volumio-stefan volumio[9721]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:19 volumio-stefan volumio[9721]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:19 volumio-stefan volumio[9721]: *** WARNING *** For more information see Feb 07 03:35:19 volumio-stefan volumio[9721]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:19 volumio-stefan volumio[9721]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:19 volumio-stefan volumio[9721]: *** WARNING *** For more information see Feb 07 03:35:19 volumio-stefan node[9721]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:19 volumio-stefan node[9721]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:19 volumio-stefan node[9721]: *** WARNING *** For more information see Feb 07 03:35:19 volumio-stefan node[9721]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:19 volumio-stefan node[9721]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:19 volumio-stefan node[9721]: *** WARNING *** For more information see Feb 07 03:35:19 volumio-stefan volumio[9721]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 03:35:19 volumio-stefan volumio[9721]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 03:35:19 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 03:35:19 volumio-stefan volumio[9721]: info: Loading plugin "spop"... Feb 07 03:35:20 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:20+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:35:20 volumio-stefan volumio[9721]: info: Loading plugin "now_playing"... Feb 07 03:35:21 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:21+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:21 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:21+02:00" level=debug msg="completed challenge" Feb 07 03:35:21 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:21 volumio-stefan go-librespot[9704]: time="2026-02-07T03:35:21+02: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 07 03:35:21 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:21 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:35:21 volumio-stefan volumio[9721]: info: Loading plugin "outputs"... Feb 07 03:35:21 volumio-stefan volumio[9721]: info: Loading plugin "albumart"... Feb 07 03:35:21 volumio-stefan volumio[9721]: info: Plugin example_plugin is not enabled Feb 07 03:35:21 volumio-stefan volumio[9721]: info: Loading plugin "inputs"... Feb 07 03:35:21 volumio-stefan volumio[9721]: info: Loading plugin "updater_comm"... Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Plugin mpdemulation is not enabled Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Loading plugin "rest_api"... Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Loading plugin "websocket"... Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Starting Socket.io Server version 1.7.4 Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Loading plugin "backup_restore"... Feb 07 03:35:22 volumio-stefan sudo[9761]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Applying required configuration parameters for plugin backup_restore Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Loading plugin "Systeminfo"... Feb 07 03:35:22 volumio-stefan volumio[9783]: Forking 3 albumart workers Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Loading i18n strings for locale en Feb 07 03:35:22 volumio-stefan volumio[9721]: Updating browse sources language Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::initPlayerControls Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:35:22 volumio-stefan volumio[9721]: Express server listening on port 3000 Feb 07 03:35:22 volumio-stefan volumio[9721]: [Metrics] WebUI: 7s 274.74ms Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreStateMachine::resetVolumioState Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreStateMachine::getcurrentVolume Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreStateMachine::pushState Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:35:22 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:22 volumio-stefan volumio[9721]: info: Volumio Network Manager: Network status updated: 2 Feb 07 03:35:23 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770428118 101 Feb 07 03:35:23 volumio-stefan volumio[9721]: 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 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Reloading queue from file Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreStateMachine::setRepeat null single undefined Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreStateMachine::pushState Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreStateMachine::setRandom null Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreStateMachine::pushState Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Setting Device type: Raspberry PI Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Completed loading Core Plugins Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Preparing to generate the ALSA configuration file Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Asound.conf file unchanged, so no further update is needed Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Output device has changed, restarting MPD Feb 07 03:35:23 volumio-stefan volumio[9721]: info: ___________ START PLUGINS ___________ Feb 07 03:35:23 volumio-stefan volumio[9721]: info: ControllerMpd::onStart: Initializing MPD Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Creating MPD Configuration file Feb 07 03:35:23 volumio-stefan sudo[9834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:35:23 volumio-stefan sudo[9834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:23 volumio-stefan sudo[9834]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:23 volumio-stefan sudo[9835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:35:23 volumio-stefan sudo[9835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:35:23 volumio-stefan volumio[9721]: info: [1770428123392] CoreMusicLibrary::Adding element Last_100 Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:35:23 volumio-stefan volumio[9721]: info: [1770428123409] CoreMusicLibrary::Adding element Webradio Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:23 volumio-stefan sudo[9838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:35:23 volumio-stefan sudo[9838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:23 volumio-stefan sudo[9838]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:23 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Initializing BBC Radios Feb 07 03:35:23 volumio-stefan sudo[9841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:35:23 volumio-stefan sudo[9841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:23 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 03:35:23 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 03:35:23 volumio-stefan systemd[1]: mpd.service: Consumed 3.254s CPU time. Feb 07 03:35:23 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 03:35:23 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 03:35:23 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:23 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 03:35:23 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 03:35:23 volumio-stefan volumio[9721]: info: Creating Spotify config file Feb 07 03:35:23 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:23 volumio-stefan sudo[9858]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 03:35:23 volumio-stefan sudo[9858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 03:35:23 volumio-stefan sudo[9858]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:23 volumio-stefan volumio[9793]: Starting albumart workers Feb 07 03:35:23 volumio-stefan volumio[9794]: Starting albumart workers Feb 07 03:35:24 volumio-stefan volumio[9795]: Starting albumart workers Feb 07 03:35:24 volumio-stefan volumio[9721]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 03:35:24 volumio-stefan volumio[9721]: info: Volumio Calling Home Feb 07 03:35:24 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 03:35:24 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:24 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:24 volumio-stefan go-librespot[9864]: go-librespot daemon starting... Feb 07 03:35:24 volumio-stefan go-librespot[9865]: time="2026-02-07T03:35:24+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:24 volumio-stefan volumio[9721]: info: [now-playing] App is listening on port 4004. Feb 07 03:35:24 volumio-stefan volumio[9721]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 03:35:24 volumio-stefan volumio[9721]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:35:24 volumio-stefan volumio[9721]: info: Discovery: Found device Volumio Stefan Feb 07 03:35:24 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:24 volumio-stefan volumio[9721]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:24 volumio-stefan volumio[9721]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:35:24 volumio-stefan volumio[9721]: info: Discovery: Found device Volumio Stefan Feb 07 03:35:24 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:24 volumio-stefan volumio[9721]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:24 volumio-stefan volumio[9721]: info: MPD Permissions set Feb 07 03:35:24 volumio-stefan volumio[9721]: info: MPD Permissions set Feb 07 03:35:24 volumio-stefan volumio[9721]: info: Volumio called home Feb 07 03:35:25 volumio-stefan volumio[9721]: info: Spotify config file written Feb 07 03:35:25 volumio-stefan go-librespot[9865]: time="2026-02-07T03:35:25+02:00" level=info msg="zeroconf server listening on port 44867" Feb 07 03:35:25 volumio-stefan sudo[9879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 03:35:25 volumio-stefan sudo[9879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:25 volumio-stefan volumio[9721]: 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 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 03:35:25 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:25 volumio-stefan go-librespot[9891]: go-librespot daemon starting... Feb 07 03:35:25 volumio-stefan sudo[9879]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=debug msg="app state loaded" Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:25 volumio-stefan volumio[9721]: info: No need to fix Spotify hosts Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:25 volumio-stefan volumio[9721]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:25 volumio-stefan volumio[9721]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 07 03:35:25 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:25+02:00" level=info msg="zeroconf server listening on port 42411" Feb 07 03:35:26 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:26+02:00" level=debug msg="obtained new client token: AACajXrSW/kpm+C2Q6r68r0CZP1t5yU/ElOmU17uJlW7ogXMhDIMGBryKFOclMsaQAONLynOlITZcCcR0z30/8QSPTWyij9xLVRDg05fVauZepKNhPMlNBT5gdCcA75kc/n8F0bNWc/xEwSxbWoP0rsHU+NWjWI18lKT4+8pKJvcG4F2iwIxv3MNfyvEKQDQfU7aVv+Twfj2o9F00ke9mv0IAEqOUJc4w217uK19A7QvnY9YuyPd" Feb 07 03:35:26 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:26 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:26+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:26 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:26+02:00" level=debug msg="completed challenge" Feb 07 03:35:26 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:26+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:27 volumio-stefan mpd[9860]: 2026-02-07T03:35:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 03:35:27 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 03:35:27 volumio-stefan sudo[9841]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:27 volumio-stefan sudo[9835]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:27 volumio-stefan volumio[9721]: info: Completed starting Core Plugins Feb 07 03:35:27 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:27 volumio-stefan volumio[9721]: info: ----- MyVolumio plugins startup ---- Feb 07 03:35:27 volumio-stefan volumio[9721]: info: ------------------------------------------- Feb 07 03:35:27 volumio-stefan volumio[9721]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 03:35:27 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:27+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:35:27 volumio-stefan volumio[9721]: error: MPD error: The expression evaluated to a falsy value: Feb 07 03:35:27 volumio-stefan volumio[9721]: assert.ok(self.idling) Feb 07 03:35:27 volumio-stefan volumio[9721]: error: The expression evaluated to a falsy value: Feb 07 03:35:27 volumio-stefan volumio[9721]: assert.ok(self.idling) Feb 07 03:35:27 volumio-stefan volumio[9721]: error: updateQueue error: null Feb 07 03:35:27 volumio-stefan volumio[9721]: info: MPD running with PID9860 Feb 07 03:35:27 volumio-stefan volumio[9721]: ,establishing connection Feb 07 03:35:27 volumio-stefan volumio[9721]: error: updateQueue error: null Feb 07 03:35:27 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:27+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:27 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:27+02:00" level=debug msg="completed challenge" Feb 07 03:35:27 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:27+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:28 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:28+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:35:28 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:28+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:28 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:28+02:00" level=debug msg="completed challenge" Feb 07 03:35:28 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:28+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:28 volumio-stefan volumio[9721]: info: go-librespot daemon successfully initialized Feb 07 03:35:28 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:28+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 03:35:29 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:29+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:29 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:29+02:00" level=debug msg="completed challenge" Feb 07 03:35:29 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:29+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:30 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 03:35:30 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:30+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:30 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:30+02:00" level=debug msg="completed challenge" Feb 07 03:35:30 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:30+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:31 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:31+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 03:35:31 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25127. Feb 07 03:35:31 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:31 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:31 volumio-stefan upmpdcli[9935]: Could not open config: /tmp/upmpdcli.conf Feb 07 03:35:31 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:31 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 03:35:31 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:31+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:31 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:31+02:00" level=debug msg="completed challenge" Feb 07 03:35:31 volumio-stefan volumio[9721]: info: Initializing connection to go-librespot Websocket Feb 07 03:35:31 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:31+02:00" level=debug msg="new websocket client" Feb 07 03:35:31 volumio-stefan volumio[9721]: info: Connection to go-librespot Websocket established Feb 07 03:35:31 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:31 volumio-stefan go-librespot[9895]: time="2026-02-07T03:35:31+02: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 07 03:35:31 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:31 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:35:31 volumio-stefan volumio[9721]: info: Connection to go-librespot Websocket closed Feb 07 03:35:32 volumio-stefan volumio[9721]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 03:35:34 volumio-stefan volumio[9721]: info: Getting Spotify volume Feb 07 03:35:34 volumio-stefan volumio[9721]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:35:34 volumio-stefan volumio[9721]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 03:35:34 volumio-stefan volumio[9721]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 03:35:34 volumio-stefan volumio[9721]: errno: -111, Feb 07 03:35:34 volumio-stefan volumio[9721]: code: 'ECONNREFUSED', Feb 07 03:35:34 volumio-stefan volumio[9721]: syscall: 'connect', Feb 07 03:35:34 volumio-stefan volumio[9721]: address: '127.0.0.1', Feb 07 03:35:34 volumio-stefan volumio[9721]: port: 9879, Feb 07 03:35:34 volumio-stefan volumio[9721]: response: undefined Feb 07 03:35:34 volumio-stefan volumio[9721]: } Feb 07 03:35:34 volumio-stefan volumio[9721]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:35:34 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 03:35:34 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:34 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:34 volumio-stefan go-librespot[9949]: go-librespot daemon starting... Feb 07 03:35:34 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:34+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:34 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:34+02:00" level=debug msg="app state loaded" Feb 07 03:35:34 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:35:35 volumio-stefan sudo[9961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 03:34' Feb 07 03:35:35 volumio-stefan sudo[9961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:35 volumio-stefan sudo[9961]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:35 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 03:35:35 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:35+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 07 03:35:35 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:35+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 07 03:35:35 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:35+02:00" level=info msg="zeroconf server listening on port 38689" Feb 07 03:35:35 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:35] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 03:35:35 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:35] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 03:35:35 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:35 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 03:35:35 volumio-stefan systemd[1]: volumio.service: Consumed 21.870s CPU time. Feb 07 03:35:35 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 03:35:35 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 03:35:35 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8111. Feb 07 03:35:35 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 03:35:35 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 03:35:35 volumio-stefan systemd[1]: volumio.service: Consumed 21.870s CPU time. Feb 07 03:35:35 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 03:35:35 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 03:35:35 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:35+02:00" level=debug msg="obtained new client token: AACH1Gg44UJwWn1lebXg29Ae//DxE3GL5IvwC1kr93iU0q13aZJD2kLBKLDZCObS8D0QwV2near5EBe3DGcSSMGf2RgUSkWUohTygZbwetNXNm8vezMBk1arCblKnjTPqS8kK7wxmVdMmf3wJE3K3EwAB36neEsaoqFau4vbODqYQmxru/lgl4AEKtYcp0Xu6yc8m37bNlvSsNotvf6Ondk1snU1rpb5kbiWfEkKeXhexak9J83YEQs=" Feb 07 03:35:35 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:35+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:36 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:36+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:36 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:36+02:00" level=debug msg="completed challenge" Feb 07 03:35:36 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:36+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:37 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:35:37 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:37+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:37 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:37+02:00" level=debug msg="completed challenge" Feb 07 03:35:37 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:37+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:37 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:37 volumio-stefan volumio[9973]: info: ----- Volumio3 ---- Feb 07 03:35:37 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:37 volumio-stefan volumio[9973]: info: ----- System startup ---- Feb 07 03:35:37 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:37 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:35:38 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:38+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:38 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:38+02:00" level=debug msg="completed challenge" Feb 07 03:35:38 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:38+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:38 volumio-stefan volumio[9973]: info: MYVOLUMIO Environment detected Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Plugin folders cleanup Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning into folder /volumio/app/plugins/ Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category audio_interface Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category miscellanea Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category music_service Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category plugins.json Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category system_controller Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category user_interface Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning into folder /data/plugins/ Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category music_service Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category system_controller Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Scanning category user_interface Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Plugin folders cleanup completed Feb 07 03:35:38 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:38 volumio-stefan volumio[9973]: info: ----- Core plugins startup ---- Feb 07 03:35:38 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Adding plugin upnp to MyMusic Plugins Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Loading plugins from folder /data/plugins/ Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Loading plugin "system"... Feb 07 03:35:38 volumio-stefan volumio[9973]: info: Loading plugin "appearance"... Feb 07 03:35:38 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:38+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 03:35:39 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:39+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:39 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:39+02:00" level=debug msg="completed challenge" Feb 07 03:35:39 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "network"... Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Refreshing Cached IP Addresses Feb 07 03:35:39 volumio-stefan sudo[10001]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 03:35:39 volumio-stefan sudo[10001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:39 volumio-stefan sudo[10003]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 03:35:39 volumio-stefan sudo[10003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:39 volumio-stefan sudo[10001]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:39 volumio-stefan sudo[10003]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "services"... Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "alsa_controller"... Feb 07 03:35:39 volumio-stefan sudo[10012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 03:35:39 volumio-stefan sudo[10012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:39 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "wizard"... Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "networkfs"... Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Starting Udev Watcher for removable devices Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Ignoring mount for partition: boot Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Ignoring mount for partition: volumio Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Ignoring mount for partition: volumio_data Feb 07 03:35:39 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "volumio_command_line_client"... Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Plugin upnp is not enabled Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "my_music"... Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "mpd"... Feb 07 03:35:39 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Plugin upnp_browser is not enabled Feb 07 03:35:39 volumio-stefan volumio[9973]: info: Loading plugin "alarm-clock"... Feb 07 03:35:40 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:40+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:40 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:40+02:00" level=debug msg="completed challenge" Feb 07 03:35:40 volumio-stefan volumio[9973]: info: Plugin airplay_emulation is not enabled Feb 07 03:35:40 volumio-stefan volumio[9973]: info: Loading plugin "last_100"... Feb 07 03:35:40 volumio-stefan volumio[9973]: info: Loading plugin "webradio"... Feb 07 03:35:40 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:40+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:40 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:40] [connect] Successful connection Feb 07 03:35:41 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:41+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 03:35:41 volumio-stefan volumio[9973]: info: Loading plugin "i2s_dacs"... Feb 07 03:35:41 volumio-stefan volumio[9973]: info: Loading plugin "volumiodiscovery"... Feb 07 03:35:41 volumio-stefan volumio[9973]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:41 volumio-stefan volumio[9973]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:41 volumio-stefan volumio[9973]: *** WARNING *** For more information see Feb 07 03:35:41 volumio-stefan volumio[9973]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:41 volumio-stefan volumio[9973]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:41 volumio-stefan volumio[9973]: *** WARNING *** For more information see Feb 07 03:35:41 volumio-stefan node[9973]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:41 volumio-stefan node[9973]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:41 volumio-stefan node[9973]: *** WARNING *** For more information see Feb 07 03:35:41 volumio-stefan node[9973]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 03:35:41 volumio-stefan node[9973]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:35:41 volumio-stefan node[9973]: *** WARNING *** For more information see Feb 07 03:35:41 volumio-stefan volumio[9973]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 03:35:41 volumio-stefan volumio[9973]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 03:35:41 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 03:35:41 volumio-stefan volumio[9973]: info: Loading plugin "spop"... Feb 07 03:35:41 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:41+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:41 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:41+02:00" level=debug msg="completed challenge" Feb 07 03:35:42 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:42+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:42 volumio-stefan go-librespot[9950]: time="2026-02-07T03:35:42+02: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 07 03:35:42 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:42 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:35:42 volumio-stefan volumio[9973]: info: Loading plugin "now_playing"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "outputs"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "albumart"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Plugin example_plugin is not enabled Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "inputs"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "updater_comm"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Plugin mpdemulation is not enabled Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "rest_api"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "websocket"... Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Starting Socket.io Server version 1.7.4 Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "backup_restore"... Feb 07 03:35:43 volumio-stefan sudo[10012]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Applying required configuration parameters for plugin backup_restore Feb 07 03:35:43 volumio-stefan volumio[9973]: info: Loading plugin "Systeminfo"... Feb 07 03:35:43 volumio-stefan volumio[10033]: Forking 3 albumart workers Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Loading i18n strings for locale en Feb 07 03:35:44 volumio-stefan volumio[9973]: Updating browse sources language Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::initPlayerControls Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: Express server listening on port 3000 Feb 07 03:35:44 volumio-stefan volumio[9973]: [Metrics] WebUI: 7s 250.25ms Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::resetVolumioState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::getcurrentVolume Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::pushState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Volumio Network Manager: Network status updated: 2 Feb 07 03:35:44 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:35:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770428140 101 Feb 07 03:35:44 volumio-stefan volumio[9973]: 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 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Reloading queue from file Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::setRepeat null single undefined Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::pushState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::setRandom null Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreStateMachine::pushState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioPushState Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Setting Device type: Raspberry PI Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Completed loading Core Plugins Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Preparing to generate the ALSA configuration file Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Asound.conf file unchanged, so no further update is needed Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Output device has changed, restarting MPD Feb 07 03:35:44 volumio-stefan volumio[9973]: info: ___________ START PLUGINS ___________ Feb 07 03:35:44 volumio-stefan sudo[10083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:35:44 volumio-stefan volumio[9973]: info: ControllerMpd::onStart: Initializing MPD Feb 07 03:35:44 volumio-stefan sudo[10083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Creating MPD Configuration file Feb 07 03:35:44 volumio-stefan sudo[10083]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:35:44 volumio-stefan volumio[9973]: info: [1770428144822] CoreMusicLibrary::Adding element Last_100 Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:44 volumio-stefan sudo[10085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:35:44 volumio-stefan sudo[10085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:35:44 volumio-stefan volumio[9973]: info: [1770428144839] CoreMusicLibrary::Adding element Webradio Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:35:44 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:44 volumio-stefan sudo[10089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:35:44 volumio-stefan sudo[10089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:44 volumio-stefan volumio[9973]: info: Initializing BBC Radios Feb 07 03:35:44 volumio-stefan sudo[10090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:35:44 volumio-stefan sudo[10090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:44 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 03:35:44 volumio-stefan sudo[10089]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:44 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 03:35:44 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 03:35:44 volumio-stefan systemd[1]: mpd.service: Consumed 3.326s CPU time. Feb 07 03:35:44 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 03:35:44 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 03:35:44 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 03:35:45 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:35:45 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:45 volumio-stefan volumio[9973]: info: Creating Spotify config file Feb 07 03:35:45 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:45 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 03:35:45 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 03:35:45 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 03:35:45 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:45 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:45 volumio-stefan go-librespot[10109]: go-librespot daemon starting... Feb 07 03:35:45 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 03:35:45 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 03:35:45 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 03:35:45 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 03:35:45 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 03:35:45 volumio-stefan go-librespot[10110]: time="2026-02-07T03:35:45+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:45 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 03:35:45 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 03:35:45 volumio-stefan sudo[10117]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 03:35:45 volumio-stefan sudo[10117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 03:35:45 volumio-stefan sudo[10117]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:45 volumio-stefan volumio[9973]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 03:35:45 volumio-stefan volumio[9973]: info: Volumio Calling Home Feb 07 03:35:45 volumio-stefan go-librespot[10110]: time="2026-02-07T03:35:45+02:00" level=info msg="zeroconf server listening on port 42531" Feb 07 03:35:45 volumio-stefan volumio[10043]: Starting albumart workers Feb 07 03:35:45 volumio-stefan volumio[10044]: Starting albumart workers Feb 07 03:35:45 volumio-stefan volumio[10045]: Starting albumart workers Feb 07 03:35:46 volumio-stefan volumio[9973]: info: [now-playing] App is listening on port 4004. Feb 07 03:35:46 volumio-stefan volumio[9973]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 03:35:46 volumio-stefan volumio[9973]: info: MPD Permissions set Feb 07 03:35:46 volumio-stefan volumio[9973]: info: MPD Permissions set Feb 07 03:35:46 volumio-stefan volumio[9973]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:35:46 volumio-stefan volumio[9973]: info: Discovery: Found device Volumio Stefan Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:46 volumio-stefan volumio[9973]: info: Spotify config file written Feb 07 03:35:46 volumio-stefan volumio[9973]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:35:46 volumio-stefan volumio[9973]: info: Discovery: Found device Volumio Stefan Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:46 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25128. Feb 07 03:35:46 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:46 volumio-stefan sudo[10127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 03:35:46 volumio-stefan sudo[10127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:46 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:35:46 volumio-stefan volumio[9973]: 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 07 03:35:46 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 03:35:46 volumio-stefan systemd[1]: go-librespot-daemon.service: Killing process 10114 (go-librespot) with signal SIGKILL. Feb 07 03:35:46 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 03:35:46 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:46 volumio-stefan upmpdcli[10128]: Could not open config: /tmp/upmpdcli.conf Feb 07 03:35:46 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:46 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:46 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 03:35:46 volumio-stefan go-librespot[10130]: go-librespot daemon starting... Feb 07 03:35:46 volumio-stefan sudo[10127]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:46 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:46+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:46 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:46+02:00" level=debug msg="app state loaded" Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:35:46 volumio-stefan volumio[9973]: info: No need to fix Spotify hosts Feb 07 03:35:47 volumio-stefan volumio[9973]: info: Volumio called home Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=info msg="zeroconf server listening on port 43733" Feb 07 03:35:47 volumio-stefan volumio[9973]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 03:35:47 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:47 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="obtained new client token: AACaDoA9WAtE0MVjP99xe+zoLuTzKFVSqICPcNiNcx5aLdcJXDx/Z9rCn2RnSHFHyP8Ttg9kNRCy+2pzTEIHw5IaG8DVx6P84TVygLP0XXrhlAoPzUOQwcsiV9PKoizaJqVLXri0S3Idoj9x4f+1mOPbkw5nEQfZfVBG84ru6/PIUS+jKoykhTeww21seTkwEgtC7CeIIZP7UE4Sa1m91cgq6IvC3wMvjRdxIDyC/hWLWkkeuQLl8fk=" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:47 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:47+02:00" level=debug msg="completed challenge" Feb 07 03:35:48 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:48+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:48 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:48+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:35:48 volumio-stefan mpd[10120]: 2026-02-07T03:35:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 03:35:48 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 03:35:48 volumio-stefan sudo[10085]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:48 volumio-stefan sudo[10090]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:48 volumio-stefan volumio[9973]: info: Completed starting Core Plugins Feb 07 03:35:48 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:48 volumio-stefan volumio[9973]: info: ----- MyVolumio plugins startup ---- Feb 07 03:35:48 volumio-stefan volumio[9973]: info: ------------------------------------------- Feb 07 03:35:48 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 03:35:48 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:48+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:48 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:48+02:00" level=debug msg="completed challenge" Feb 07 03:35:48 volumio-stefan volumio[9973]: error: MPD error: The expression evaluated to a falsy value: Feb 07 03:35:48 volumio-stefan volumio[9973]: assert.ok(self.idling) Feb 07 03:35:48 volumio-stefan volumio[9973]: error: The expression evaluated to a falsy value: Feb 07 03:35:48 volumio-stefan volumio[9973]: assert.ok(self.idling) Feb 07 03:35:48 volumio-stefan volumio[9973]: error: updateQueue error: null Feb 07 03:35:48 volumio-stefan volumio[9973]: info: MPD running with PID10120 Feb 07 03:35:48 volumio-stefan volumio[9973]: ,establishing connection Feb 07 03:35:48 volumio-stefan volumio[9973]: error: updateQueue error: null Feb 07 03:35:48 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:48+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:49 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:49+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 03:35:49 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:49+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:49 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:49+02:00" level=debug msg="completed challenge" Feb 07 03:35:50 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:50+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:50 volumio-stefan volumio[9973]: info: go-librespot daemon successfully initialized Feb 07 03:35:50 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:50+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=debug msg="completed challenge" Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=debug msg="completed challenge" Feb 07 03:35:51 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:51+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:52 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:52+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:52 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:52+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:52 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:52+02:00" level=debug msg="completed challenge" Feb 07 03:35:52 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:52+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:52 volumio-stefan go-librespot[10131]: time="2026-02-07T03:35:52+02: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 07 03:35:52 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:35:52 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:35:53 volumio-stefan volumio[9973]: info: Initializing connection to go-librespot Websocket Feb 07 03:35:53 volumio-stefan volumio[9973]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 03:35:53 volumio-stefan volumio[9973]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 03:35:55 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 03:35:55 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:55 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:35:55 volumio-stefan go-librespot[10188]: go-librespot daemon starting... Feb 07 03:35:55 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:55+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:35:55 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:55+02:00" level=debug msg="app state loaded" Feb 07 03:35:55 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:35:56 volumio-stefan volumio[9973]: info: Initializing connection to go-librespot Websocket Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="new websocket client" Feb 07 03:35:56 volumio-stefan volumio[9973]: info: Connection to go-librespot Websocket established Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=info msg="zeroconf server listening on port 39147" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="obtained new client token: AACP1+m5WFebURZut2yd45n5Goxgt84MPzvg/eJvQKUXchMoaNmoLirrBWpMHTQHDjAJFgVkRZzwz2ixCqKhpuWQBYofW83gBTjScbz0303KmifPYlIbbNMsd/7s1lGoFd/+ylXzK1pGAKp8vaEmfES2EYACEkBohyfwUIxt5dKKlQlWQHISXmUwMvRpQc/qRo7+qFwd+ePpqhpkIMDXsdbda3v3zKrLS4yxzGw9vVTa5Z9HlqKgrEs=" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=debug msg="completed challenge" Feb 07 03:35:56 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:56+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 03:35:57 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 03:35:57 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:57+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:35:57 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:57+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:57 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:57+02:00" level=debug msg="completed challenge" Feb 07 03:35:57 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:57+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:58 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 03:35:58 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 03:35:58 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:58 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:35:58 volumio-stefan volumio[9973]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 03:35:58 volumio-stefan volumio[9973]: info: MyVolumio login type: Token Feb 07 03:35:58 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 03:35:58 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 03:35:58 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:58+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:35:58 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:58+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:58 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:58+02:00" level=debug msg="completed challenge" Feb 07 03:35:58 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:58+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:35:59 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 03:35:59 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 03:35:59 volumio-stefan volumio[9973]: info: Streaming services startup Feb 07 03:35:59 volumio-stefan volumio[9973]: info: Starting Streaming Daemon Feb 07 03:35:59 volumio-stefan sudo[10200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 03:35:59 volumio-stefan sudo[10200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:35:59 volumio-stefan volumio[9973]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 03:35:59 volumio-stefan sudo[10200]: pam_unix(sudo:session): session closed for user root Feb 07 03:35:59 volumio-stefan volumio[9973]: info: Getting Spotify volume Feb 07 03:35:59 volumio-stefan volumio[9973]: error: Cannot start Volumio Streaming Daemon Feb 07 03:35:59 volumio-stefan volumio[9973]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 03:35:59 volumio-stefan volumio[9973]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 03:35:59 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:59+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 03:35:59 volumio-stefan volumio[9973]: 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 07 03:35:59 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:59+02:00" level=debug msg="completed keyexchange" Feb 07 03:35:59 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:59+02:00" level=debug msg="completed challenge" Feb 07 03:35:59 volumio-stefan volumio[9973]: info: CoreCommandRouter::volumioGetState Feb 07 03:35:59 volumio-stefan volumio[9973]: info: CorePlayQueue::getTrack 0 Feb 07 03:35:59 volumio-stefan go-librespot[10189]: time="2026-02-07T03:35:59+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:00 volumio-stefan volumio[9973]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 03:36:00 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:00+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Feb 07 03:36:00 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:00+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 03:36:00 volumio-stefan volumio[9973]: info: MyVolumio token set successfully Feb 07 03:36:00 volumio-stefan volumio[9973]: info: MYVOLUMIO: Adding device Feb 07 03:36:00 volumio-stefan volumio[9973]: info: MYVOLUMIO: Evaluating Server Feb 07 03:36:00 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:00+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:00 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:00+02:00" level=debug msg="completed challenge" Feb 07 03:36:01 volumio-stefan volumio[9973]: info: MyVolumio status changed Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Streaming services startup Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Starting Streaming Daemon Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Removing browser output: myVolumio user plan is not superstar Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Removing audio output: Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Stoppping Tunnel 1 Feb 07 03:36:01 volumio-stefan sudo[10241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 03:36:01 volumio-stefan sudo[10241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:01 volumio-stefan sudo[10243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 07 03:36:01 volumio-stefan sudo[10243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:01 volumio-stefan systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 03:36:01 volumio-stefan systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 03:36:01 volumio-stefan sudo[10241]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:01 volumio-stefan systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 03:36:01 volumio-stefan systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 03:36:01 volumio-stefan systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 03:36:01 volumio-stefan systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 07 03:36:01 volumio-stefan sudo[10243]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:01 volumio-stefan volumio[9973]: error: Cannot start Volumio Streaming Daemon Feb 07 03:36:01 volumio-stefan volumio[9973]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 03:36:01 volumio-stefan volumio[9973]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Remote SSH Stopped Feb 07 03:36:01 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:01+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:01 volumio-stefan volumio[9973]: info: Setting Geolocation for MyVolumio to eu8 Feb 07 03:36:01 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:01 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:01 volumio-stefan volumio[9973]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:01 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25129. Feb 07 03:36:01 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:36:01 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:36:01 volumio-stefan upmpdcli[10246]: Could not open config: /tmp/upmpdcli.conf Feb 07 03:36:01 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:36:01 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 03:36:01 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:01+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:36:01 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:01+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:01 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:01+02:00" level=debug msg="completed challenge" Feb 07 03:36:02 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:02+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:02 volumio-stefan go-librespot[10189]: time="2026-02-07T03:36:02+02: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 07 03:36:02 volumio-stefan volumio[9973]: info: Successfully Added MyVolumio device Feb 07 03:36:02 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:36:02 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:36:02 volumio-stefan volumio[9973]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:36:02 volumio-stefan volumio[9973]: Error: socket hang up Feb 07 03:36:02 volumio-stefan volumio[9973]: at connResetException (node:internal/errors:720:14) Feb 07 03:36:02 volumio-stefan volumio[9973]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 03:36:02 volumio-stefan volumio[9973]: at Socket.emit (node:events:526:35) Feb 07 03:36:02 volumio-stefan volumio[9973]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 03:36:02 volumio-stefan volumio[9973]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 03:36:02 volumio-stefan volumio[9973]: code: 'ECONNRESET', Feb 07 03:36:02 volumio-stefan volumio[9973]: response: undefined Feb 07 03:36:02 volumio-stefan volumio[9973]: } Feb 07 03:36:02 volumio-stefan volumio[9973]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:36:02 volumio-stefan sudo[10261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 03:35' Feb 07 03:36:02 volumio-stefan sudo[10261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:02 volumio-stefan sudo[10261]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:03 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:36:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 03:36:03 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:36:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 03:36:03 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:36:03 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 03:36:03 volumio-stefan systemd[1]: volumio.service: Consumed 25.862s CPU time. Feb 07 03:36:03 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 03:36:03 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 03:36:03 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8112. Feb 07 03:36:03 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 03:36:03 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 03:36:03 volumio-stefan systemd[1]: volumio.service: Consumed 25.862s CPU time. Feb 07 03:36:03 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 03:36:03 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 03:36:05 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 03:36:05 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:36:05 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:36:05 volumio-stefan go-librespot[10291]: go-librespot daemon starting... Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=debug msg="app state loaded" Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:36:05 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:05 volumio-stefan volumio[10277]: info: ----- Volumio3 ---- Feb 07 03:36:05 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:05 volumio-stefan volumio[10277]: info: ----- System startup ---- Feb 07 03:36:05 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 07 03:36:05 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:05+02:00" level=info msg="zeroconf server listening on port 34529" Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="obtained new client token: AAC3LbOeCRdV8rEKtq8unvIdTTspwT1YjE+Ce1FXe6BtYzECKtledSB/XToPtT6AsqDAHDftz20KhK9wl4+HxBNAAk9y9qZnc3wYyWkfcj86QQetATkkKWAFlSsffPM2+Jlj3cvs63psjAFxUXVE+kARDmUCZkfeXuiFNz/yJtVTal6AW7uAWsr+Df2WzHNp2cazK1ua7ijZ0wj5EbgwUpDPxHW+H+U1qUCkTPdBQD4k15UyFayU" Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="completed challenge" Feb 07 03:36:06 volumio-stefan volumio[10277]: info: MYVOLUMIO Environment detected Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Plugin folders cleanup Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning into folder /volumio/app/plugins/ Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category audio_interface Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category miscellanea Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category music_service Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category plugins.json Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category system_controller Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category user_interface Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning into folder /data/plugins/ Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category music_service Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category system_controller Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Scanning category user_interface Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Plugin folders cleanup completed Feb 07 03:36:06 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:06 volumio-stefan volumio[10277]: info: ----- Core plugins startup ---- Feb 07 03:36:06 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Adding plugin upnp to MyMusic Plugins Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Loading plugins from folder /data/plugins/ Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Loading plugin "system"... Feb 07 03:36:06 volumio-stefan volumio[10277]: info: Loading plugin "appearance"... Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:06 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:06+02:00" level=debug msg="completed challenge" Feb 07 03:36:07 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:07+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "network"... Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Refreshing Cached IP Addresses Feb 07 03:36:07 volumio-stefan sudo[10314]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 03:36:07 volumio-stefan sudo[10314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:07 volumio-stefan sudo[10314]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:07 volumio-stefan sudo[10316]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 03:36:07 volumio-stefan sudo[10316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "services"... Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "alsa_controller"... Feb 07 03:36:07 volumio-stefan sudo[10316]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:07 volumio-stefan sudo[10324]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 03:36:07 volumio-stefan sudo[10324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:07 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "wizard"... Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "networkfs"... Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Starting Udev Watcher for removable devices Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Ignoring mount for partition: boot Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Ignoring mount for partition: volumio Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Ignoring mount for partition: volumio_data Feb 07 03:36:07 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "volumio_command_line_client"... Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Plugin upnp is not enabled Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "my_music"... Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "mpd"... Feb 07 03:36:07 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:07+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:36:07 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:07+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:07 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:07+02:00" level=debug msg="completed challenge" Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Plugin upnp_browser is not enabled Feb 07 03:36:07 volumio-stefan volumio[10277]: info: Loading plugin "alarm-clock"... Feb 07 03:36:08 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:08 volumio-stefan volumio[10277]: info: Plugin airplay_emulation is not enabled Feb 07 03:36:08 volumio-stefan volumio[10277]: info: Loading plugin "last_100"... Feb 07 03:36:08 volumio-stefan volumio[10277]: info: Loading plugin "webradio"... Feb 07 03:36:08 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:36:08] [connect] Successful connection Feb 07 03:36:08 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:08+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 03:36:08 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:08+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:08 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:08+02:00" level=debug msg="completed challenge" Feb 07 03:36:09 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:09+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:09 volumio-stefan volumio[10277]: info: Loading plugin "i2s_dacs"... Feb 07 03:36:09 volumio-stefan volumio[10277]: info: Loading plugin "volumiodiscovery"... Feb 07 03:36:09 volumio-stefan volumio[10277]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 03:36:09 volumio-stefan volumio[10277]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:36:09 volumio-stefan volumio[10277]: *** WARNING *** For more information see Feb 07 03:36:09 volumio-stefan volumio[10277]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 03:36:09 volumio-stefan volumio[10277]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:36:09 volumio-stefan volumio[10277]: *** WARNING *** For more information see Feb 07 03:36:09 volumio-stefan node[10277]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 03:36:09 volumio-stefan node[10277]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:36:09 volumio-stefan node[10277]: *** WARNING *** For more information see Feb 07 03:36:09 volumio-stefan node[10277]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 03:36:09 volumio-stefan node[10277]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 03:36:09 volumio-stefan node[10277]: *** WARNING *** For more information see Feb 07 03:36:09 volumio-stefan volumio[10277]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 03:36:09 volumio-stefan volumio[10277]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 03:36:09 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 03:36:09 volumio-stefan volumio[10277]: info: Loading plugin "spop"... Feb 07 03:36:09 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 03:36:10 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:10+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:10 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:10+02:00" level=debug msg="completed challenge" Feb 07 03:36:10 volumio-stefan volumio[10277]: info: Loading plugin "now_playing"... Feb 07 03:36:10 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:10+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "outputs"... Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "albumart"... Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Plugin example_plugin is not enabled Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "inputs"... Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "updater_comm"... Feb 07 03:36:11 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:11+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Plugin mpdemulation is not enabled Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "rest_api"... Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "websocket"... Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Starting Socket.io Server version 1.7.4 Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "backup_restore"... Feb 07 03:36:11 volumio-stefan sudo[10324]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:11 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:11+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:11 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:11+02:00" level=debug msg="completed challenge" Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Applying required configuration parameters for plugin backup_restore Feb 07 03:36:11 volumio-stefan volumio[10277]: info: Loading plugin "Systeminfo"... Feb 07 03:36:11 volumio-stefan volumio[10346]: Forking 3 albumart workers Feb 07 03:36:12 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:12+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:12 volumio-stefan go-librespot[10292]: time="2026-02-07T03:36:12+02: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 07 03:36:12 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:36:12 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Loading i18n strings for locale en Feb 07 03:36:12 volumio-stefan volumio[10277]: Updating browse sources language Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::initPlayerControls Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: Express server listening on port 3000 Feb 07 03:36:12 volumio-stefan volumio[10277]: [Metrics] WebUI: 7s 326.34ms Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::resetVolumioState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::getcurrentVolume Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::pushState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CorePlayQueue::getTrack 0 Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioPushState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Volumio Network Manager: Network status updated: 2 Feb 07 03:36:12 volumio-stefan volumio-remote-updater[658]: [2026-02-07 03:36:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770428168 101 Feb 07 03:36:12 volumio-stefan volumio[10277]: 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 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Reloading queue from file Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::setRepeat null single undefined Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::pushState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CorePlayQueue::getTrack 0 Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioPushState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::setRandom null Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreStateMachine::pushState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CorePlayQueue::getTrack 0 Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioPushState Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Setting Device type: Raspberry PI Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Completed loading Core Plugins Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Preparing to generate the ALSA configuration file Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Asound.conf file unchanged, so no further update is needed Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Output device has changed, restarting MPD Feb 07 03:36:12 volumio-stefan sudo[10397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:36:12 volumio-stefan sudo[10397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:12 volumio-stefan sudo[10397]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:12 volumio-stefan volumio[10277]: info: ___________ START PLUGINS ___________ Feb 07 03:36:12 volumio-stefan volumio[10277]: info: ControllerMpd::onStart: Initializing MPD Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Creating MPD Configuration file Feb 07 03:36:12 volumio-stefan sudo[10400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:36:12 volumio-stefan sudo[10400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:36:12 volumio-stefan volumio[10277]: info: [1770428172862] CoreMusicLibrary::Adding element Last_100 Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:36:12 volumio-stefan sudo[10402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 03:36:12 volumio-stefan sudo[10402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 03:36:12 volumio-stefan volumio[10277]: info: [1770428172879] CoreMusicLibrary::Adding element Webradio Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 03:36:12 volumio-stefan sudo[10402]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:12 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:36:12 volumio-stefan sudo[10404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 03:36:12 volumio-stefan sudo[10404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:12 volumio-stefan volumio[10277]: info: Initializing BBC Radios Feb 07 03:36:12 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 03:36:13 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 03:36:13 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:13 volumio-stefan volumio[10277]: info: Creating Spotify config file Feb 07 03:36:13 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:13 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 03:36:13 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 03:36:13 volumio-stefan systemd[1]: mpd.service: Consumed 3.323s CPU time. Feb 07 03:36:13 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 03:36:13 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 03:36:13 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 03:36:13 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 03:36:13 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 03:36:13 volumio-stefan sudo[10422]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 03:36:13 volumio-stefan sudo[10422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 03:36:13 volumio-stefan sudo[10422]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:13 volumio-stefan volumio[10358]: Starting albumart workers Feb 07 03:36:13 volumio-stefan volumio[10277]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 03:36:13 volumio-stefan volumio[10277]: info: Volumio Calling Home Feb 07 03:36:13 volumio-stefan volumio[10357]: Starting albumart workers Feb 07 03:36:13 volumio-stefan volumio[10356]: Starting albumart workers Feb 07 03:36:13 volumio-stefan volumio[10277]: info: [now-playing] App is listening on port 4004. Feb 07 03:36:13 volumio-stefan volumio[10277]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 03:36:14 volumio-stefan volumio[10277]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:36:14 volumio-stefan volumio[10277]: info: Discovery: Found device Volumio Stefan Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioGetState Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CorePlayQueue::getTrack 0 Feb 07 03:36:14 volumio-stefan volumio[10277]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 03:36:14 volumio-stefan volumio[10277]: info: Discovery: Found device Volumio Stefan Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioGetState Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CorePlayQueue::getTrack 0 Feb 07 03:36:14 volumio-stefan volumio[10277]: info: MPD Permissions set Feb 07 03:36:14 volumio-stefan volumio[10277]: info: MPD Permissions set Feb 07 03:36:14 volumio-stefan volumio[10277]: info: Volumio called home Feb 07 03:36:14 volumio-stefan volumio[10277]: info: Spotify config file written Feb 07 03:36:14 volumio-stefan sudo[10430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 03:36:14 volumio-stefan sudo[10430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 03:36:14 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:36:14 volumio-stefan volumio[10277]: 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 07 03:36:14 volumio-stefan go-librespot[10433]: go-librespot daemon starting... Feb 07 03:36:14 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:36:14 volumio-stefan sudo[10430]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:14+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:36:14 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:14+02:00" level=debug msg="app state loaded" Feb 07 03:36:14 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 03:36:14 volumio-stefan volumio[10277]: info: No need to fix Spotify hosts Feb 07 03:36:14 volumio-stefan volumio[10277]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 03:36:15 volumio-stefan volumio[10277]: info: CoreCommandRouter::volumioGetState Feb 07 03:36:15 volumio-stefan volumio[10277]: info: CorePlayQueue::getTrack 0 Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=info msg="zeroconf server listening on port 33829" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="obtained new client token: AAB2fstb2tUJtOm+jhUKNchccLkeHjMnYCKYJ6wxVklxUNUBJre6ZxApahCwZnIf1pEQMd8SF6xwuP/4qlprw0J5FAi5Wdc3VSTZffejjorBB11Z99+w19CrfVWY64tkOTELHhuO3LcnwgyxZmhbTyHXvZmH01HWB1jgaMfAl+UkJS+y12xokH+mwdxj0UW8ZKJbLuDefgvCzTGevtQ72kbfSnO1h+UVuKfa02HyBcmN6f2iM5q8nzI=" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:15 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:15+02:00" level=debug msg="completed challenge" Feb 07 03:36:16 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:16 volumio-stefan mpd[10424]: 2026-02-07T03:36:16 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 03:36:16 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 03:36:16 volumio-stefan sudo[10404]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:16 volumio-stefan sudo[10400]: pam_unix(sudo:session): session closed for user root Feb 07 03:36:16 volumio-stefan volumio[10277]: info: Completed starting Core Plugins Feb 07 03:36:16 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:16 volumio-stefan volumio[10277]: info: ----- MyVolumio plugins startup ---- Feb 07 03:36:16 volumio-stefan volumio[10277]: info: ------------------------------------------- Feb 07 03:36:16 volumio-stefan volumio[10277]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 03:36:16 volumio-stefan volumio[10277]: error: MPD error: The expression evaluated to a falsy value: Feb 07 03:36:16 volumio-stefan volumio[10277]: assert.ok(self.idling) Feb 07 03:36:16 volumio-stefan volumio[10277]: error: The expression evaluated to a falsy value: Feb 07 03:36:16 volumio-stefan volumio[10277]: assert.ok(self.idling) Feb 07 03:36:16 volumio-stefan volumio[10277]: info: MPD running with PID10424 Feb 07 03:36:16 volumio-stefan volumio[10277]: ,establishing connection Feb 07 03:36:16 volumio-stefan volumio[10277]: error: updateQueue error: null Feb 07 03:36:16 volumio-stefan volumio[10277]: error: updateQueue error: null Feb 07 03:36:16 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:16+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 03:36:16 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25130. Feb 07 03:36:16 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=debug msg="completed challenge" Feb 07 03:36:17 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 03:36:17 volumio-stefan upmpdcli[10477]: Could not open config: /tmp/upmpdcli.conf Feb 07 03:36:17 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:36:17 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=debug msg="completed challenge" Feb 07 03:36:17 volumio-stefan volumio[10277]: info: go-librespot daemon successfully initialized Feb 07 03:36:17 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:18 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:18+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 03:36:18 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:18+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:18 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:18+02:00" level=debug msg="completed challenge" Feb 07 03:36:18 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:18+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:19 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:19+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 03:36:19 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:19+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:19 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:19+02:00" level=debug msg="completed challenge" Feb 07 03:36:19 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:19+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:20 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:20+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 03:36:20 volumio-stefan volumio[10277]: info: Initializing connection to go-librespot Websocket Feb 07 03:36:20 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:20+02:00" level=debug msg="new websocket client" Feb 07 03:36:20 volumio-stefan volumio[10277]: info: Connection to go-librespot Websocket established Feb 07 03:36:21 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:21+02:00" level=debug msg="completed keyexchange" Feb 07 03:36:21 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:21+02:00" level=debug msg="completed challenge" Feb 07 03:36:21 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 03:36:21 volumio-stefan go-librespot[10434]: time="2026-02-07T03:36:21+02: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 07 03:36:21 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 03:36:21 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 03:36:21 volumio-stefan volumio[10277]: info: Connection to go-librespot Websocket closed Feb 07 03:36:21 volumio-stefan volumio[10277]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 03:36:23 volumio-stefan volumio[10277]: info: Getting Spotify volume Feb 07 03:36:23 volumio-stefan volumio[10277]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:36:23 volumio-stefan volumio[10277]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 03:36:23 volumio-stefan volumio[10277]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 03:36:23 volumio-stefan volumio[10277]: errno: -111, Feb 07 03:36:23 volumio-stefan volumio[10277]: code: 'ECONNREFUSED', Feb 07 03:36:23 volumio-stefan volumio[10277]: syscall: 'connect', Feb 07 03:36:23 volumio-stefan volumio[10277]: address: '127.0.0.1', Feb 07 03:36:23 volumio-stefan volumio[10277]: port: 9879, Feb 07 03:36:23 volumio-stefan volumio[10277]: response: undefined Feb 07 03:36:23 volumio-stefan volumio[10277]: } Feb 07 03:36:23 volumio-stefan volumio[10277]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 03:36:24 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 03:36:24 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:36:24 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 03:36:24 volumio-stefan go-librespot[10504]: go-librespot daemon starting... Feb 07 03:36:24 volumio-stefan go-librespot[10505]: time="2026-02-07T03:36:24+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 03:36:24 volumio-stefan go-librespot[10505]: time="2026-02-07T03:36:24+02:00" level=debug msg="app state loaded" Feb 07 03:36:24 volumio-stefan go-librespot[10505]: time="2026-02-07T03:36:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 03:36:24 volumio-stefan sudo[10514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 03:35' Feb 07 03:36:24 volumio-stefan sudo[10514]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"