Feb 07 05:52:00 volumio-stefan volumio[8020]: info: Applying required configuration parameters for plugin backup_restore Feb 07 05:52:00 volumio-stefan go-librespot[8042]: time="2026-02-07T05:52:00+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:00 volumio-stefan go-librespot[8042]: time="2026-02-07T05:52:00+02:00" level=debug msg="completed challenge" Feb 07 05:52:00 volumio-stefan volumio[8020]: info: Loading plugin "Systeminfo"... Feb 07 05:52:00 volumio-stefan volumio[8092]: Forking 3 albumart workers Feb 07 05:52:00 volumio-stefan go-librespot[8042]: time="2026-02-07T05:52:00+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:00 volumio-stefan go-librespot[8042]: time="2026-02-07T05:52: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 05:52:00 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:00 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:00 volumio-stefan volumio[8020]: info: Loading i18n strings for locale en Feb 07 05:52:00 volumio-stefan volumio[8020]: Updating browse sources language Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::initPlayerControls Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: Express server listening on port 3000 Feb 07 05:52:00 volumio-stefan volumio[8020]: [Metrics] WebUI: 7s 391.27ms Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::resetVolumioState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::getcurrentVolume Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::pushState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: Volumio Network Manager: Network status updated: 2 Feb 07 05:52:00 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770436316 101 Feb 07 05:52:00 volumio-stefan volumio[8020]: 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 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:00 volumio-stefan volumio[8020]: info: Reloading queue from file Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::setRepeat null single undefined Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::pushState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::setRandom null Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreStateMachine::pushState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:00 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:00 volumio-stefan volumio[8020]: info: Setting Device type: Raspberry PI Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Completed loading Core Plugins Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Preparing to generate the ALSA configuration file Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Asound.conf file unchanged, so no further update is needed Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Output device has changed, restarting MPD Feb 07 05:52:01 volumio-stefan volumio[8020]: info: ___________ START PLUGINS ___________ Feb 07 05:52:01 volumio-stefan sudo[8142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:52:01 volumio-stefan sudo[8142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:01 volumio-stefan sudo[8142]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:01 volumio-stefan volumio[8020]: info: ControllerMpd::onStart: Initializing MPD Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Creating MPD Configuration file Feb 07 05:52:01 volumio-stefan sudo[8144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:52:01 volumio-stefan sudo[8144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:52:01 volumio-stefan volumio[8020]: info: [1770436321241] CoreMusicLibrary::Adding element Last_100 Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:01 volumio-stefan sudo[8147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:52:01 volumio-stefan sudo[8147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:52:01 volumio-stefan volumio[8020]: info: [1770436321260] CoreMusicLibrary::Adding element Webradio Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:01 volumio-stefan sudo[8150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:52:01 volumio-stefan sudo[8150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Initializing BBC Radios Feb 07 05:52:01 volumio-stefan sudo[8147]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:01 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 05:52:01 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 05:52:01 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 05:52:01 volumio-stefan systemd[1]: mpd.service: Consumed 3.276s CPU time. Feb 07 05:52:01 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 05:52:01 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 05:52:01 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:01 volumio-stefan volumio[8020]: info: Creating Spotify config file Feb 07 05:52:01 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:01 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 05:52:01 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 05:52:01 volumio-stefan volumio[8104]: Starting albumart workers Feb 07 05:52:01 volumio-stefan sudo[8167]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 05:52:01 volumio-stefan sudo[8167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 05:52:01 volumio-stefan volumio[8103]: Starting albumart workers Feb 07 05:52:01 volumio-stefan sudo[8167]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:01 volumio-stefan volumio[8102]: Starting albumart workers Feb 07 05:52:01 volumio-stefan volumio[8020]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 05:52:02 volumio-stefan volumio[8020]: info: Volumio Calling Home Feb 07 05:52:02 volumio-stefan volumio[8020]: info: [now-playing] App is listening on port 4004. Feb 07 05:52:02 volumio-stefan volumio[8020]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 05:52:02 volumio-stefan volumio[8020]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:52:02 volumio-stefan volumio[8020]: info: Discovery: Found device Volumio Stefan Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:02 volumio-stefan volumio[8020]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:52:02 volumio-stefan volumio[8020]: info: Discovery: Found device Volumio Stefan Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:02 volumio-stefan volumio[8020]: info: MPD Permissions set Feb 07 05:52:02 volumio-stefan volumio[8020]: info: MPD Permissions set Feb 07 05:52:02 volumio-stefan volumio[8020]: info: Spotify config file written Feb 07 05:52:02 volumio-stefan sudo[8190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 05:52:02 volumio-stefan sudo[8190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:02 volumio-stefan volumio[8020]: 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 05:52:02 volumio-stefan volumio[8020]: info: Volumio called home Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:02 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:03 volumio-stefan go-librespot[8195]: go-librespot daemon starting... Feb 07 05:52:03 volumio-stefan sudo[8190]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=debug msg="app state loaded" Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:03 volumio-stefan volumio[8020]: info: No need to fix Spotify hosts Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:03 volumio-stefan volumio[8020]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+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 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+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 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=info msg="zeroconf server listening on port 41389" Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:03 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=debug msg="obtained new client token: AAB7mZulWhTYlhdP6jYnB3c8dcNkLR3A33c77Lj2vWPREK4ZZWGFgaFyGfdcgRmxmiaxtuVq6UCMlkn/9f+bDHUjplT+ObfTw++v7+FbeSQ7yWdt0N1d8Bv6MxKq9RobsHcMX0/r7wSKYJAj3xkXnWMPhKJKEDEUR/dDhY6bvd9B0LvG4YjzTUUez4Qvp/NerGsNmLPrHz1dlUKOaAbh9BajnTMszWUedL5CUb+/wgjbqfAKNaXsihA=" Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=debug msg="completed challenge" Feb 07 05:52:03 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:03+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:04 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:04+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:04 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:04+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:04 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:04+02:00" level=debug msg="completed challenge" Feb 07 05:52:04 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:04+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:04 volumio-stefan mpd[8169]: 2026-02-07T05:52:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 05:52:04 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 05:52:04 volumio-stefan sudo[8150]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:04 volumio-stefan sudo[8144]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:04 volumio-stefan volumio[8020]: info: Completed starting Core Plugins Feb 07 05:52:04 volumio-stefan volumio[8020]: info: ------------------------------------------- Feb 07 05:52:04 volumio-stefan volumio[8020]: info: ----- MyVolumio plugins startup ---- Feb 07 05:52:04 volumio-stefan volumio[8020]: info: ------------------------------------------- Feb 07 05:52:04 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 05:52:04 volumio-stefan volumio[8020]: error: MPD error: The expression evaluated to a falsy value: Feb 07 05:52:04 volumio-stefan volumio[8020]: assert.ok(self.idling) Feb 07 05:52:04 volumio-stefan volumio[8020]: error: The expression evaluated to a falsy value: Feb 07 05:52:04 volumio-stefan volumio[8020]: assert.ok(self.idling) Feb 07 05:52:04 volumio-stefan volumio[8020]: error: updateQueue error: null Feb 07 05:52:04 volumio-stefan volumio[8020]: info: MPD running with PID8169 Feb 07 05:52:04 volumio-stefan volumio[8020]: ,establishing connection Feb 07 05:52:04 volumio-stefan volumio[8020]: error: updateQueue error: null Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=debug msg="completed challenge" Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:05 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:05+02:00" level=debug msg="completed challenge" Feb 07 05:52:06 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:06 volumio-stefan volumio[8020]: info: go-librespot daemon successfully initialized Feb 07 05:52:06 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:52:06 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:06+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:06 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:06+02:00" level=debug msg="completed challenge" Feb 07 05:52:06 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:06+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:07 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:07+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:52:07 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:07+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:07 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:07+02:00" level=debug msg="completed challenge" Feb 07 05:52:08 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:08+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:08 volumio-stefan go-librespot[8206]: time="2026-02-07T05:52:08+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 05:52:08 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:08 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:09 volumio-stefan volumio[8020]: info: Initializing connection to go-librespot Websocket Feb 07 05:52:09 volumio-stefan volumio[8020]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 05:52:09 volumio-stefan volumio[8020]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 05:52:11 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 07 05:52:11 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:11 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:11 volumio-stefan go-librespot[8234]: go-librespot daemon starting... Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=debug msg="app state loaded" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+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 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+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 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+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 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=info msg="zeroconf server listening on port 38021" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=debug msg="obtained new client token: AABALz3Z1Kspfv78DHDcP4A3+G23j+0cqJs8XMi/EXiOYuzl89L3bqw2wNhusAYdynJ7ISoidBRsuWFHoXaUL0NSIEHKmOQXxfcWC5HHV5ji4fHyrY9L+pwDN0x5j1ZemXvD5vt4zhkSfPPpD/OQhZ9MobBy6Wa3Yl3x1Bw0GXs+5/F0lip0PpxcIHUXIFafOE2DqdA9sqyBsIsbcpYnIucAo7DxycVPHL6JuykXCaD6R7be0Dk/KzQ=" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=debug msg="completed challenge" Feb 07 05:52:11 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:11+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:12 volumio-stefan volumio[8020]: info: Initializing connection to go-librespot Websocket Feb 07 05:52:12 volumio-stefan volumio[8020]: info: Connection to go-librespot Websocket established Feb 07 05:52:12 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:12+02:00" level=debug msg="new websocket client" Feb 07 05:52:12 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:12+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:12 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:12+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:12 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:12+02:00" level=debug msg="completed challenge" Feb 07 05:52:12 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:12+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:13 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:13+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:13 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:13+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:13 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:13+02:00" level=debug msg="completed challenge" Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 05:52:13 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 05:52:13 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:13+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:13 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25665. Feb 07 05:52:13 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:13 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:13 volumio-stefan upmpdcli[8244]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:52:13 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:13 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:52:13 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:13+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=debug msg="completed challenge" Feb 07 05:52:14 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 05:52:14 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 05:52:14 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:14 volumio-stefan volumio[8020]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:14 volumio-stefan volumio[8020]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 05:52:14 volumio-stefan volumio[8020]: info: MyVolumio login type: Token Feb 07 05:52:14 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 05:52:14 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=debug msg="completed challenge" Feb 07 05:52:14 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:14 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 05:52:14 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 05:52:14 volumio-stefan volumio[8020]: info: Streaming services startup Feb 07 05:52:14 volumio-stefan volumio[8020]: info: Starting Streaming Daemon Feb 07 05:52:15 volumio-stefan sudo[8247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 05:52:15 volumio-stefan sudo[8247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:15 volumio-stefan volumio[8020]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 05:52:15 volumio-stefan sudo[8247]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:15 volumio-stefan volumio[8020]: error: Cannot start Volumio Streaming Daemon Feb 07 05:52:15 volumio-stefan volumio[8020]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 05:52:15 volumio-stefan volumio[8020]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 05:52:15 volumio-stefan volumio[8020]: info: Getting Spotify volume Feb 07 05:52:15 volumio-stefan volumio[8020]: 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 05:52:15 volumio-stefan volumio[8020]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:15 volumio-stefan volumio[8020]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:15 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:15+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:52:15 volumio-stefan volumio[8020]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 05:52:15 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:15+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:15 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:15+02:00" level=debug msg="completed challenge" Feb 07 05:52:16 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:16 volumio-stefan go-librespot[8235]: time="2026-02-07T05:52:16+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 05:52:16 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:16 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:16 volumio-stefan volumio[8020]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:52:16 volumio-stefan volumio[8020]: Error: socket hang up Feb 07 05:52:16 volumio-stefan volumio[8020]: at connResetException (node:internal/errors:720:14) Feb 07 05:52:16 volumio-stefan volumio[8020]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 05:52:16 volumio-stefan volumio[8020]: at Socket.emit (node:events:526:35) Feb 07 05:52:16 volumio-stefan volumio[8020]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 05:52:16 volumio-stefan volumio[8020]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 05:52:16 volumio-stefan volumio[8020]: code: 'ECONNRESET', Feb 07 05:52:16 volumio-stefan volumio[8020]: response: undefined Feb 07 05:52:16 volumio-stefan volumio[8020]: } Feb 07 05:52:16 volumio-stefan volumio[8020]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:52:16 volumio-stefan sudo[8281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 05:51' Feb 07 05:52:16 volumio-stefan sudo[8281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:17 volumio-stefan sudo[8281]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:17 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 05:52:17 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 05:52:17 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:17 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 05:52:17 volumio-stefan systemd[1]: volumio.service: Consumed 25.046s CPU time. Feb 07 05:52:17 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:52:17 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:52:17 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8317. Feb 07 05:52:17 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:52:17 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 05:52:17 volumio-stefan systemd[1]: volumio.service: Consumed 25.046s CPU time. Feb 07 05:52:17 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 05:52:17 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:52:19 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 07 05:52:19 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:19 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:19 volumio-stefan volumio[8293]: info: ----- Volumio3 ---- Feb 07 05:52:19 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:19 volumio-stefan volumio[8293]: info: ----- System startup ---- Feb 07 05:52:19 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:19 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:19 volumio-stefan go-librespot[8314]: go-librespot daemon starting... Feb 07 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+02:00" level=debug msg="app state loaded" Feb 07 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+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 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+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 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+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 05:52:19 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:19+02:00" level=info msg="zeroconf server listening on port 34329" Feb 07 05:52:20 volumio-stefan volumio[8293]: info: MYVOLUMIO Environment detected Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Plugin folders cleanup Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning into folder /volumio/app/plugins/ Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category audio_interface Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category miscellanea Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category music_service Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category plugins.json Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category system_controller Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category user_interface Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning into folder /data/plugins/ Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category music_service Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category system_controller Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Scanning category user_interface Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Plugin folders cleanup completed Feb 07 05:52:20 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:20 volumio-stefan volumio[8293]: info: ----- Core plugins startup ---- Feb 07 05:52:20 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Adding plugin upnp to MyMusic Plugins Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Loading plugins from folder /data/plugins/ Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Loading plugin "system"... Feb 07 05:52:20 volumio-stefan volumio[8293]: info: Loading plugin "appearance"... Feb 07 05:52:21 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:21+02:00" level=debug msg="obtained new client token: AADJChL2jPPYhGd1TdL585VtwJDJQSWFX+dUwLR1Z/pEVcPMA0q6DTSqWFPPlnBlxfr23qHJjRX+pqtmxkF/O4UsVJ9auzy9D1da/uYvuesUijaoxDFR89F1PVnlNsVHGaUVLNrm3P/sJxAdECQE4UcqL5wjpimDOPHoLYhIlZDWDeFJT6BA5gunGJzJ80ELsc3Pmofsge9ZS3CCIREPAHrP6Y7OdcYxiNkJuApAhNblknuJ5LHscRE=" Feb 07 05:52:21 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:21+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "network"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Refreshing Cached IP Addresses Feb 07 05:52:21 volumio-stefan sudo[8331]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 05:52:21 volumio-stefan sudo[8331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:21 volumio-stefan sudo[8333]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 05:52:21 volumio-stefan sudo[8333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:21 volumio-stefan sudo[8331]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "services"... Feb 07 05:52:21 volumio-stefan sudo[8333]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "alsa_controller"... Feb 07 05:52:21 volumio-stefan sudo[8341]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 05:52:21 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:21+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:21 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:21+02:00" level=debug msg="completed challenge" Feb 07 05:52:21 volumio-stefan sudo[8341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:21 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "wizard"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "networkfs"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Starting Udev Watcher for removable devices Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Ignoring mount for partition: boot Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Ignoring mount for partition: volumio Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Ignoring mount for partition: volumio_data Feb 07 05:52:21 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "volumio_command_line_client"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Plugin upnp is not enabled Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "my_music"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "mpd"... Feb 07 05:52:21 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Plugin upnp_browser is not enabled Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "alarm-clock"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Plugin airplay_emulation is not enabled Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "last_100"... Feb 07 05:52:21 volumio-stefan volumio[8293]: info: Loading plugin "webradio"... Feb 07 05:52:22 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:22] [connect] Successful connection Feb 07 05:52:22 volumio-stefan volumio[8293]: info: Loading plugin "i2s_dacs"... Feb 07 05:52:22 volumio-stefan volumio[8293]: info: Loading plugin "volumiodiscovery"... Feb 07 05:52:22 volumio-stefan volumio[8293]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:22 volumio-stefan volumio[8293]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:22 volumio-stefan volumio[8293]: *** WARNING *** For more information see Feb 07 05:52:22 volumio-stefan volumio[8293]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:22 volumio-stefan volumio[8293]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:22 volumio-stefan volumio[8293]: *** WARNING *** For more information see Feb 07 05:52:22 volumio-stefan node[8293]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:22 volumio-stefan node[8293]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:22 volumio-stefan node[8293]: *** WARNING *** For more information see Feb 07 05:52:22 volumio-stefan node[8293]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:22 volumio-stefan node[8293]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:22 volumio-stefan node[8293]: *** WARNING *** For more information see Feb 07 05:52:22 volumio-stefan volumio[8293]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 05:52:22 volumio-stefan volumio[8293]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 05:52:22 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:52:23 volumio-stefan volumio[8293]: info: Loading plugin "spop"... Feb 07 05:52:23 volumio-stefan volumio[8293]: info: Loading plugin "now_playing"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "outputs"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "albumart"... Feb 07 05:52:25 volumio-stefan sudo[8341]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Plugin example_plugin is not enabled Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "inputs"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "updater_comm"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Plugin mpdemulation is not enabled Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "rest_api"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "websocket"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Starting Socket.io Server version 1.7.4 Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "backup_restore"... Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Applying required configuration parameters for plugin backup_restore Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading plugin "Systeminfo"... Feb 07 05:52:25 volumio-stefan volumio[8363]: Forking 3 albumart workers Feb 07 05:52:25 volumio-stefan volumio[8293]: info: Loading i18n strings for locale en Feb 07 05:52:25 volumio-stefan volumio[8293]: Updating browse sources language Feb 07 05:52:25 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::initPlayerControls Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: Express server listening on port 3000 Feb 07 05:52:26 volumio-stefan volumio[8293]: [Metrics] WebUI: 7s 333.06ms Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::resetVolumioState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::getcurrentVolume Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::pushState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Volumio Network Manager: Network status updated: 2 Feb 07 05:52:26 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770436342 101 Feb 07 05:52:26 volumio-stefan volumio[8293]: 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 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Reloading queue from file Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::setRepeat null single undefined Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::pushState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::setRandom null Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreStateMachine::pushState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Setting Device type: Raspberry PI Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Completed loading Core Plugins Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Preparing to generate the ALSA configuration file Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Asound.conf file unchanged, so no further update is needed Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Output device has changed, restarting MPD Feb 07 05:52:26 volumio-stefan sudo[8414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:52:26 volumio-stefan sudo[8414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:26 volumio-stefan volumio[8293]: info: ___________ START PLUGINS ___________ Feb 07 05:52:26 volumio-stefan sudo[8414]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:26 volumio-stefan volumio[8293]: info: ControllerMpd::onStart: Initializing MPD Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Creating MPD Configuration file Feb 07 05:52:26 volumio-stefan sudo[8416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:52:26 volumio-stefan sudo[8416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:52:26 volumio-stefan volumio[8293]: info: [1770436346638] CoreMusicLibrary::Adding element Last_100 Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:52:26 volumio-stefan volumio[8293]: info: [1770436346656] CoreMusicLibrary::Adding element Webradio Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:26 volumio-stefan sudo[8419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:52:26 volumio-stefan sudo[8419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:26 volumio-stefan sudo[8419]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:26 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 05:52:26 volumio-stefan sudo[8422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:52:26 volumio-stefan sudo[8422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Initializing BBC Radios Feb 07 05:52:26 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 05:52:26 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 05:52:26 volumio-stefan systemd[1]: mpd.service: Consumed 3.254s CPU time. Feb 07 05:52:26 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 05:52:26 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 05:52:26 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 05:52:26 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:26 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:26 volumio-stefan volumio[8293]: info: Creating Spotify config file Feb 07 05:52:26 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:26 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:26 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:26+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:26 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:26+02:00" level=debug msg="completed challenge" Feb 07 05:52:27 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:26+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:27 volumio-stefan sudo[8439]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 05:52:27 volumio-stefan sudo[8439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 05:52:27 volumio-stefan sudo[8439]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:27 volumio-stefan volumio[8373]: Starting albumart workers Feb 07 05:52:27 volumio-stefan volumio[8293]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 05:52:27 volumio-stefan volumio[8374]: Starting albumart workers Feb 07 05:52:27 volumio-stefan volumio[8293]: info: Volumio Calling Home Feb 07 05:52:27 volumio-stefan volumio[8375]: Starting albumart workers Feb 07 05:52:27 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:27+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:27 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:27+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:27 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:27+02:00" level=debug msg="completed challenge" Feb 07 05:52:27 volumio-stefan go-librespot[8315]: time="2026-02-07T05:52:27+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:27 volumio-stefan volumio[8293]: info: [now-playing] App is listening on port 4004. Feb 07 05:52:27 volumio-stefan volumio[8293]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 05:52:27 volumio-stefan volumio[8293]: info: MPD Permissions set Feb 07 05:52:27 volumio-stefan volumio[8293]: info: MPD Permissions set Feb 07 05:52:27 volumio-stefan volumio[8293]: info: Spotify config file written Feb 07 05:52:27 volumio-stefan sudo[8446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 05:52:27 volumio-stefan sudo[8446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:27 volumio-stefan volumio[8293]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:52:27 volumio-stefan volumio[8293]: info: Discovery: Found device Volumio Stefan Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:28 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 05:52:28 volumio-stefan systemd[1]: go-librespot-daemon.service: Killing process 8323 (go-librespot) with signal SIGKILL. Feb 07 05:52:28 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 05:52:28 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:28 volumio-stefan volumio[8293]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:52:28 volumio-stefan volumio[8293]: info: Discovery: Found device Volumio Stefan Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:28 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:28 volumio-stefan sudo[8446]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:28 volumio-stefan go-librespot[8448]: go-librespot daemon starting... Feb 07 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+02:00" level=debug msg="app state loaded" Feb 07 05:52:28 volumio-stefan volumio[8293]: 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 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:28 volumio-stefan volumio[8293]: info: Volumio called home Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:28 volumio-stefan volumio[8293]: info: No need to fix Spotify hosts Feb 07 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+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 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+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 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+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 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+02:00" level=info msg="zeroconf server listening on port 39009" Feb 07 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+02:00" level=debug msg="obtained new client token: AAAbfviv5j+P0t/s+d5OI+M7GmDoEjTTofLBvTs9qxd42ZJSt0VWk92aiXHEGodps4bFQrd2m0nVgHyr3BhXC0RWX9FDiZb8wP1Sx+WFarnToOOLbvTt2R9021QtyKuhqmmh7jMNNBfTDwt9YlCAwSRUnsAlm2RDkAi6HyU3T7kbHYHZPmxC8iMRqfbJDJNl2NImfKux6L+o1Rm21vQ7+I2i+1Ih6ZMBwgqXVXZPjR/TUVyvbDmE1l8=" Feb 07 05:52:28 volumio-stefan volumio[8293]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+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 05:52:28 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:28+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 05:52:28 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25666. Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:28 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:28 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:29 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:29+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:29 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:29 volumio-stefan upmpdcli[8486]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:52:29 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:29 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:52:29 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:29+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:29 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:29+02:00" level=debug msg="completed challenge" Feb 07 05:52:29 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:29+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:29 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:29+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 05:52:29 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:29+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 05:52:30 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:30+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:30 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:30+02:00" level=debug msg="completed challenge" Feb 07 05:52:30 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:30+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:30 volumio-stefan mpd[8441]: 2026-02-07T05:52:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 05:52:30 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 05:52:30 volumio-stefan sudo[8422]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:30 volumio-stefan sudo[8416]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:30 volumio-stefan volumio[8293]: info: Completed starting Core Plugins Feb 07 05:52:30 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:30 volumio-stefan volumio[8293]: info: ----- MyVolumio plugins startup ---- Feb 07 05:52:30 volumio-stefan volumio[8293]: info: ------------------------------------------- Feb 07 05:52:30 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 05:52:30 volumio-stefan volumio[8293]: error: MPD error: The expression evaluated to a falsy value: Feb 07 05:52:30 volumio-stefan volumio[8293]: assert.ok(self.idling) Feb 07 05:52:30 volumio-stefan volumio[8293]: error: The expression evaluated to a falsy value: Feb 07 05:52:30 volumio-stefan volumio[8293]: assert.ok(self.idling) Feb 07 05:52:30 volumio-stefan volumio[8293]: info: MPD running with PID8441 Feb 07 05:52:30 volumio-stefan volumio[8293]: ,establishing connection Feb 07 05:52:30 volumio-stefan volumio[8293]: error: updateQueue error: null Feb 07 05:52:30 volumio-stefan volumio[8293]: error: updateQueue error: null Feb 07 05:52:31 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:31+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:52:31 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:31+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:31 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:31+02:00" level=debug msg="completed challenge" Feb 07 05:52:31 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:31 volumio-stefan volumio[8293]: info: go-librespot daemon successfully initialized Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=debug msg="completed challenge" Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=debug msg="completed challenge" Feb 07 05:52:32 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:32+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:33 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:33+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:33 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:33+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:33 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:33+02:00" level=debug msg="completed challenge" Feb 07 05:52:33 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:33+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:33 volumio-stefan go-librespot[8449]: time="2026-02-07T05:52:33+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 05:52:33 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:33 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:34 volumio-stefan volumio[8293]: info: Initializing connection to go-librespot Websocket Feb 07 05:52:34 volumio-stefan volumio[8293]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 05:52:35 volumio-stefan volumio[8293]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 05:52:36 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 05:52:36 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:36 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:36 volumio-stefan go-librespot[8507]: go-librespot daemon starting... Feb 07 05:52:36 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:36+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:36 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:36+02:00" level=debug msg="app state loaded" Feb 07 05:52:36 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+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 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+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 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+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 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=info msg="zeroconf server listening on port 34097" Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=debug msg="obtained new client token: AABYf58z6zoPqeSQRxbCwAUHuF8Wqsz11qHndyS1TThNJURnX6isknY9zXY8h5oPuvqIalbc4Kav40AeYNc+XCL5HZwLPCzplxmvyaY0dy5LBrwxr2IPqAv1g5ViW3zyUlcjr3ETfvBetvcLvInNIKHmCSzHVL4s0fP7LB1sxKH4HRQHumv2D256IivUWdAFt8r/maoptnvRt9qZRal8IwNXHeFfhUsnxYVdEyCGr38omddSKNG4" Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=debug msg="completed challenge" Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:37 volumio-stefan volumio[8293]: info: Initializing connection to go-librespot Websocket Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=debug msg="new websocket client" Feb 07 05:52:37 volumio-stefan volumio[8293]: info: Connection to go-librespot Websocket established Feb 07 05:52:37 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:37+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:38 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:38+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:38 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:38+02:00" level=debug msg="completed challenge" Feb 07 05:52:38 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:38+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:38 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:38+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 05:52:38 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 05:52:38 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:38+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:38 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:38+02:00" level=debug msg="completed challenge" Feb 07 05:52:39 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:39 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 05:52:39 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 05:52:39 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:39 volumio-stefan volumio[8293]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:39 volumio-stefan volumio[8293]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 05:52:39 volumio-stefan volumio[8293]: info: MyVolumio login type: Token Feb 07 05:52:39 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 05:52:39 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 05:52:39 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:39+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 05:52:39 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:39+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:39 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:39+02:00" level=debug msg="completed challenge" Feb 07 05:52:39 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:40 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 05:52:40 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 05:52:40 volumio-stefan volumio[8293]: info: Streaming services startup Feb 07 05:52:40 volumio-stefan volumio[8293]: info: Starting Streaming Daemon Feb 07 05:52:40 volumio-stefan sudo[8518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 05:52:40 volumio-stefan sudo[8518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:40 volumio-stefan volumio[8293]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 05:52:40 volumio-stefan sudo[8518]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:40 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:52:40 volumio-stefan volumio[8293]: error: Cannot start Volumio Streaming Daemon Feb 07 05:52:40 volumio-stefan volumio[8293]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 05:52:40 volumio-stefan volumio[8293]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 05:52:40 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:40+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:40 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:40+02:00" level=debug msg="completed challenge" Feb 07 05:52:40 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:40+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:40 volumio-stefan volumio[8293]: info: Getting Spotify volume Feb 07 05:52:40 volumio-stefan volumio[8293]: 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 05:52:40 volumio-stefan volumio[8293]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:40 volumio-stefan volumio[8293]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:41 volumio-stefan volumio[8293]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 05:52:41 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:41+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:52:41 volumio-stefan volumio[8293]: info: MyVolumio token set successfully Feb 07 05:52:41 volumio-stefan volumio[8293]: info: MYVOLUMIO: Adding device Feb 07 05:52:41 volumio-stefan volumio[8293]: info: MYVOLUMIO: Evaluating Server Feb 07 05:52:41 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:41+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:41 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:41+02:00" level=debug msg="completed challenge" Feb 07 05:52:41 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:41+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:41 volumio-stefan go-librespot[8508]: time="2026-02-07T05:52:41+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 05:52:42 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:42 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:42 volumio-stefan volumio[8293]: info: MyVolumio status changed Feb 07 05:52:42 volumio-stefan volumio[8293]: info: Streaming services startup Feb 07 05:52:42 volumio-stefan volumio[8293]: info: Starting Streaming Daemon Feb 07 05:52:42 volumio-stefan volumio[8293]: info: Removing browser output: myVolumio user plan is not superstar Feb 07 05:52:42 volumio-stefan volumio[8293]: info: Removing audio output: Feb 07 05:52:42 volumio-stefan volumio[8293]: info: Stoppping Tunnel 1 Feb 07 05:52:42 volumio-stefan sudo[8560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 05:52:42 volumio-stefan sudo[8560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:42 volumio-stefan volumio[8293]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:52:42 volumio-stefan sudo[8562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 07 05:52:42 volumio-stefan sudo[8562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:42 volumio-stefan volumio[8293]: Error: socket hang up Feb 07 05:52:42 volumio-stefan volumio[8293]: at connResetException (node:internal/errors:720:14) Feb 07 05:52:42 volumio-stefan volumio[8293]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 05:52:42 volumio-stefan volumio[8293]: at Socket.emit (node:events:526:35) Feb 07 05:52:42 volumio-stefan volumio[8293]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 05:52:42 volumio-stefan volumio[8293]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 05:52:42 volumio-stefan volumio[8293]: code: 'ECONNRESET', Feb 07 05:52:42 volumio-stefan volumio[8293]: response: undefined Feb 07 05:52:42 volumio-stefan volumio[8293]: } Feb 07 05:52:42 volumio-stefan volumio[8293]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:52:42 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 05:52:42 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 05:52:42 volumio-stefan sudo[8560]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:42 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 05:52:42 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 05:52:42 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 05:52:42 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 05:52:42 volumio-stefan sudo[8562]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:42 volumio-stefan sudo[8579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 05:51' Feb 07 05:52:42 volumio-stefan sudo[8579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:43 volumio-stefan sudo[8579]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:43 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 05:52:43 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 05:52:43 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:43 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 05:52:43 volumio-stefan systemd[1]: volumio.service: Consumed 25.641s CPU time. Feb 07 05:52:43 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:52:43 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:52:43 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8318. Feb 07 05:52:43 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:52:43 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 05:52:43 volumio-stefan systemd[1]: volumio.service: Consumed 25.641s CPU time. Feb 07 05:52:43 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 05:52:43 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:52:44 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25667. Feb 07 05:52:44 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:44 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:44 volumio-stefan upmpdcli[8606]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:52:44 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:44 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:52:45 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 05:52:45 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:45 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:45 volumio-stefan go-librespot[8613]: go-librespot daemon starting... Feb 07 05:52:45 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=debug msg="app state loaded" Feb 07 05:52:45 volumio-stefan volumio[8591]: info: ----- Volumio3 ---- Feb 07 05:52:45 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:45 volumio-stefan volumio[8591]: info: ----- System startup ---- Feb 07 05:52:45 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+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 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+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 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+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 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=info msg="zeroconf server listening on port 38475" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=debug msg="obtained new client token: AACa92U++Z51e1ik87qONMx5tiRu6ZqOolbYfPKxRf6YXHlZC1ScPGbQj5TuFQVNTXFkp3P9vokbOCHXFgW3GSJ1GIDFMEn6gbckOzubrEfl64Sjfy45WdMO1xKo8rVvPt9YBz2Fc21aR/bjIC2VXtG0m6X3TtHjKabLWLi2akBcy6qQc5vx0FJ6KSu3w7xgKPQA609vYw0FnEuOS2EIpXGMf10odCjOh7qnsn9TFxYUqmhM2seHMeo=" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=debug msg="completed challenge" Feb 07 05:52:45 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:45+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:46 volumio-stefan volumio[8591]: info: MYVOLUMIO Environment detected Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Plugin folders cleanup Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning into folder /volumio/app/plugins/ Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category audio_interface Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category miscellanea Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category music_service Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category plugins.json Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category system_controller Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category user_interface Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning into folder /data/plugins/ Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category music_service Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category system_controller Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Scanning category user_interface Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Plugin folders cleanup completed Feb 07 05:52:46 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:46 volumio-stefan volumio[8591]: info: ----- Core plugins startup ---- Feb 07 05:52:46 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Adding plugin upnp to MyMusic Plugins Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Loading plugins from folder /data/plugins/ Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Loading plugin "system"... Feb 07 05:52:46 volumio-stefan volumio[8591]: info: Loading plugin "appearance"... Feb 07 05:52:46 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:46+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:46 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:46+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:46 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:46+02:00" level=debug msg="completed challenge" Feb 07 05:52:46 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:46+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "network"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Refreshing Cached IP Addresses Feb 07 05:52:47 volumio-stefan sudo[8630]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 05:52:47 volumio-stefan sudo[8630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:47 volumio-stefan sudo[8632]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 05:52:47 volumio-stefan sudo[8632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:47 volumio-stefan sudo[8630]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:47 volumio-stefan sudo[8632]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "services"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "alsa_controller"... Feb 07 05:52:47 volumio-stefan sudo[8642]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 05:52:47 volumio-stefan sudo[8642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:47 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:47+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:47 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "wizard"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "networkfs"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Starting Udev Watcher for removable devices Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Ignoring mount for partition: boot Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Ignoring mount for partition: volumio Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Ignoring mount for partition: volumio_data Feb 07 05:52:47 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "volumio_command_line_client"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Plugin upnp is not enabled Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "my_music"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "mpd"... Feb 07 05:52:47 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:47+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:47 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:47+02:00" level=debug msg="completed challenge" Feb 07 05:52:47 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:47+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Plugin upnp_browser is not enabled Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "alarm-clock"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Plugin airplay_emulation is not enabled Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "last_100"... Feb 07 05:52:47 volumio-stefan volumio[8591]: info: Loading plugin "webradio"... Feb 07 05:52:48 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:48] [connect] Successful connection Feb 07 05:52:48 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:48+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:52:48 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:48+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:48 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:48+02:00" level=debug msg="completed challenge" Feb 07 05:52:48 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:48+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:49 volumio-stefan volumio[8591]: info: Loading plugin "i2s_dacs"... Feb 07 05:52:49 volumio-stefan volumio[8591]: info: Loading plugin "volumiodiscovery"... Feb 07 05:52:49 volumio-stefan volumio[8591]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:49 volumio-stefan volumio[8591]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:49 volumio-stefan volumio[8591]: *** WARNING *** For more information see Feb 07 05:52:49 volumio-stefan volumio[8591]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:49 volumio-stefan volumio[8591]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:49 volumio-stefan volumio[8591]: *** WARNING *** For more information see Feb 07 05:52:49 volumio-stefan node[8591]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:49 volumio-stefan node[8591]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:49 volumio-stefan node[8591]: *** WARNING *** For more information see Feb 07 05:52:49 volumio-stefan node[8591]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:52:49 volumio-stefan node[8591]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:52:49 volumio-stefan node[8591]: *** WARNING *** For more information see Feb 07 05:52:49 volumio-stefan volumio[8591]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 05:52:49 volumio-stefan volumio[8591]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 05:52:49 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:52:49 volumio-stefan volumio[8591]: info: Loading plugin "spop"... Feb 07 05:52:49 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:52:49 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:49+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:49 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:49+02:00" level=debug msg="completed challenge" Feb 07 05:52:49 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:49+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:50 volumio-stefan volumio[8591]: info: Loading plugin "now_playing"... Feb 07 05:52:50 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:50+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:52:50 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:50+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:50 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:50+02:00" level=debug msg="completed challenge" Feb 07 05:52:51 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:51+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:51 volumio-stefan go-librespot[8614]: time="2026-02-07T05:52:51+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 05:52:51 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:51 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "outputs"... Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "albumart"... Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Plugin example_plugin is not enabled Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "inputs"... Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "updater_comm"... Feb 07 05:52:51 volumio-stefan sudo[8642]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Plugin mpdemulation is not enabled Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "rest_api"... Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "websocket"... Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Starting Socket.io Server version 1.7.4 Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "backup_restore"... Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Applying required configuration parameters for plugin backup_restore Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading plugin "Systeminfo"... Feb 07 05:52:51 volumio-stefan volumio[8662]: Forking 3 albumart workers Feb 07 05:52:51 volumio-stefan volumio[8591]: info: Loading i18n strings for locale en Feb 07 05:52:51 volumio-stefan volumio[8591]: Updating browse sources language Feb 07 05:52:51 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::initPlayerControls Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: Express server listening on port 3000 Feb 07 05:52:52 volumio-stefan volumio[8591]: [Metrics] WebUI: 7s 342.73ms Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::resetVolumioState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::getcurrentVolume Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::pushState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Volumio Network Manager: Network status updated: 2 Feb 07 05:52:52 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:52:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770436368 101 Feb 07 05:52:52 volumio-stefan volumio[8591]: 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 05:52:52 volumio-stefan volumio[8591]: info: Reloading queue from file Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Setting Device type: Raspberry PI Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::setRepeat null single undefined Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::pushState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::setRandom null Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreStateMachine::pushState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioPushState Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Completed loading Core Plugins Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Preparing to generate the ALSA configuration file Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Asound.conf file unchanged, so no further update is needed Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Output device has changed, restarting MPD Feb 07 05:52:52 volumio-stefan volumio[8591]: info: ___________ START PLUGINS ___________ Feb 07 05:52:52 volumio-stefan volumio[8591]: info: ControllerMpd::onStart: Initializing MPD Feb 07 05:52:52 volumio-stefan sudo[8714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Creating MPD Configuration file Feb 07 05:52:52 volumio-stefan sudo[8714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:52 volumio-stefan sudo[8715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:52:52 volumio-stefan sudo[8714]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:52 volumio-stefan sudo[8715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:52:52 volumio-stefan volumio[8591]: info: [1770436372661] CoreMusicLibrary::Adding element Last_100 Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:52:52 volumio-stefan volumio[8591]: info: [1770436372671] CoreMusicLibrary::Adding element Webradio Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Initializing BBC Radios Feb 07 05:52:52 volumio-stefan sudo[8721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:52:52 volumio-stefan sudo[8721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:52 volumio-stefan sudo[8718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:52:52 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 05:52:52 volumio-stefan sudo[8718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:52 volumio-stefan sudo[8718]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:52 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 05:52:52 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 05:52:52 volumio-stefan systemd[1]: mpd.service: Consumed 3.374s CPU time. Feb 07 05:52:52 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 05:52:52 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 05:52:52 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:52 volumio-stefan volumio[8591]: info: Creating Spotify config file Feb 07 05:52:52 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:52 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 05:52:52 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 05:52:53 volumio-stefan sudo[8738]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 05:52:53 volumio-stefan sudo[8738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 05:52:53 volumio-stefan sudo[8738]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:53 volumio-stefan volumio[8672]: Starting albumart workers Feb 07 05:52:53 volumio-stefan volumio[8673]: Starting albumart workers Feb 07 05:52:53 volumio-stefan volumio[8591]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 05:52:53 volumio-stefan volumio[8591]: info: Volumio Calling Home Feb 07 05:52:53 volumio-stefan volumio[8674]: Starting albumart workers Feb 07 05:52:53 volumio-stefan volumio[8591]: info: [now-playing] App is listening on port 4004. Feb 07 05:52:53 volumio-stefan volumio[8591]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 05:52:53 volumio-stefan volumio[8591]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:52:53 volumio-stefan volumio[8591]: info: Discovery: Found device Volumio Stefan Feb 07 05:52:53 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:53 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:53 volumio-stefan volumio[8591]: info: MPD Permissions set Feb 07 05:52:53 volumio-stefan volumio[8591]: info: MPD Permissions set Feb 07 05:52:53 volumio-stefan volumio[8591]: info: Spotify config file written Feb 07 05:52:53 volumio-stefan volumio[8591]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:52:53 volumio-stefan volumio[8591]: info: Discovery: Found device Volumio Stefan Feb 07 05:52:53 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:53 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:53 volumio-stefan sudo[8745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 05:52:54 volumio-stefan sudo[8745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:52:54 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:54 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:52:54 volumio-stefan go-librespot[8747]: go-librespot daemon starting... Feb 07 05:52:54 volumio-stefan sudo[8745]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:54 volumio-stefan volumio[8591]: 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 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=debug msg="app state loaded" Feb 07 05:52:54 volumio-stefan volumio[8591]: info: Volumio called home Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:52:54 volumio-stefan volumio[8591]: info: No need to fix Spotify hosts Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+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 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+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 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+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 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=info msg="zeroconf server listening on port 36807" Feb 07 05:52:54 volumio-stefan volumio[8591]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=debug msg="obtained new client token: AAAQBnAcrrKijRDhrQ4HkEiGgGWQ3Sua3dBZ9YnZaYWW1jRXeOVkQQFNJKNgnvsy1y/8wAI2v/wRmhmn2+5tORuNV/xwCY7/dlCr6JoiJSqtDKhUI9fgGoQo4BECyyIsrJeA44oAtW2c2fm72dZOk8AkZDL5WFkDOYAmJ1lr7kGCHbWpCd9MbMHvqepPSrzScC0TaVlGjaofy+XNEy3zY37sIjp+sQjdSc2EaXy36BHvE+7Y2jkMhSc=" Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioGetState Feb 07 05:52:54 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=debug msg="completed challenge" Feb 07 05:52:54 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:54+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:55 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:55+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:52:55 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:55+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:55 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:55+02:00" level=debug msg="completed challenge" Feb 07 05:52:55 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:55+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:56 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:56+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:52:56 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:56+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:56 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:56+02:00" level=debug msg="completed challenge" Feb 07 05:52:56 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:56+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:56 volumio-stefan mpd[8740]: 2026-02-07T05:52:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 05:52:56 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 05:52:56 volumio-stefan sudo[8721]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:56 volumio-stefan sudo[8715]: pam_unix(sudo:session): session closed for user root Feb 07 05:52:56 volumio-stefan volumio[8591]: info: Completed starting Core Plugins Feb 07 05:52:56 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:56 volumio-stefan volumio[8591]: info: ----- MyVolumio plugins startup ---- Feb 07 05:52:56 volumio-stefan volumio[8591]: info: ------------------------------------------- Feb 07 05:52:56 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 05:52:56 volumio-stefan volumio[8591]: error: MPD error: The expression evaluated to a falsy value: Feb 07 05:52:56 volumio-stefan volumio[8591]: assert.ok(self.idling) Feb 07 05:52:56 volumio-stefan volumio[8591]: error: The expression evaluated to a falsy value: Feb 07 05:52:56 volumio-stefan volumio[8591]: assert.ok(self.idling) Feb 07 05:52:56 volumio-stefan volumio[8591]: error: updateQueue error: null Feb 07 05:52:56 volumio-stefan volumio[8591]: info: MPD running with PID8740 Feb 07 05:52:56 volumio-stefan volumio[8591]: ,establishing connection Feb 07 05:52:56 volumio-stefan volumio[8591]: error: updateQueue error: null Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=debug msg="completed challenge" Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:57 volumio-stefan volumio[8591]: info: go-librespot daemon successfully initialized Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:57 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:57+02:00" level=debug msg="completed challenge" Feb 07 05:52:58 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:58+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:58 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:58+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:52:59 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:59+02:00" level=debug msg="completed keyexchange" Feb 07 05:52:59 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:59+02:00" level=debug msg="completed challenge" Feb 07 05:52:59 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:59+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:52:59 volumio-stefan go-librespot[8748]: time="2026-02-07T05:52:59+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 05:52:59 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:59 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:52:59 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25668. Feb 07 05:52:59 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:59 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:52:59 volumio-stefan upmpdcli[8805]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:52:59 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:52:59 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:53:00 volumio-stefan volumio[8591]: info: Initializing connection to go-librespot Websocket Feb 07 05:53:00 volumio-stefan volumio[8591]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 05:53:01 volumio-stefan volumio[8591]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 05:53:02 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 05:53:02 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:02 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:02 volumio-stefan go-librespot[8806]: go-librespot daemon starting... Feb 07 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+02:00" level=debug msg="app state loaded" Feb 07 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+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 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+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 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+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 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+02:00" level=info msg="zeroconf server listening on port 45073" Feb 07 05:53:02 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:02+02:00" level=debug msg="obtained new client token: AABs+L50YFk67t5LEUdqYdwUn/yQGk0tEo7VxxiBMhqkZosN9/4TJ0faEicllRUljUaVCCS3V8RziFmoo5RU4JiOMgdpKUZnIdpJMyxSgSt7rdjDtDbHQFUbYCkAX1FQExXO/dvZuLcexfW0vyG1Bmk4cEZvWb3BoSbxsXseSzSQaZTncFovH90e3rvca+2NuUAD8pJUgWgTH6lUZ2UwsP1ZQo2dM3bLwJpwIJ10a3fDe/RuqZiZF6c=" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="completed challenge" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:03 volumio-stefan volumio[8591]: info: Initializing connection to go-librespot Websocket Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="new websocket client" Feb 07 05:53:03 volumio-stefan volumio[8591]: info: Connection to go-librespot Websocket established Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=debug msg="completed challenge" Feb 07 05:53:03 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:03+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:04 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:04+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:53:04 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:04+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:04 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:04+02:00" level=debug msg="completed challenge" Feb 07 05:53:04 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:04+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 05:53:04 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 05:53:05 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:05+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:53:05 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:05+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:05 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:05+02:00" level=debug msg="completed challenge" Feb 07 05:53:05 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 05:53:05 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 05:53:05 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:05 volumio-stefan volumio[8591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:05 volumio-stefan volumio[8591]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 05:53:05 volumio-stefan volumio[8591]: info: MyVolumio login type: Token Feb 07 05:53:05 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 05:53:05 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 05:53:05 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:05+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:06 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:06+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 05:53:06 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 05:53:06 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 05:53:06 volumio-stefan volumio[8591]: info: Streaming services startup Feb 07 05:53:06 volumio-stefan volumio[8591]: info: Starting Streaming Daemon Feb 07 05:53:06 volumio-stefan sudo[8817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 05:53:06 volumio-stefan sudo[8817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:06 volumio-stefan volumio[8591]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 05:53:06 volumio-stefan sudo[8817]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:06 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:06+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:53:06 volumio-stefan volumio[8591]: error: Cannot start Volumio Streaming Daemon Feb 07 05:53:06 volumio-stefan volumio[8591]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 05:53:06 volumio-stefan volumio[8591]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 05:53:06 volumio-stefan volumio[8591]: info: Getting Spotify volume Feb 07 05:53:06 volumio-stefan volumio[8591]: 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 05:53:06 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:06+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:06 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:06+02:00" level=debug msg="completed challenge" Feb 07 05:53:06 volumio-stefan volumio[8591]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:06 volumio-stefan volumio[8591]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:07 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:07+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:07 volumio-stefan volumio[8591]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 05:53:07 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:07+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:07 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:07+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:07 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:07+02:00" level=debug msg="completed challenge" Feb 07 05:53:07 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:07+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:07 volumio-stefan go-librespot[8807]: time="2026-02-07T05:53:07+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 05:53:07 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:07 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:53:07 volumio-stefan volumio[8591]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:53:07 volumio-stefan volumio[8591]: Error: socket hang up Feb 07 05:53:07 volumio-stefan volumio[8591]: at connResetException (node:internal/errors:720:14) Feb 07 05:53:07 volumio-stefan volumio[8591]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 05:53:07 volumio-stefan volumio[8591]: at Socket.emit (node:events:526:35) Feb 07 05:53:07 volumio-stefan volumio[8591]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 05:53:07 volumio-stefan volumio[8591]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 05:53:07 volumio-stefan volumio[8591]: code: 'ECONNRESET', Feb 07 05:53:07 volumio-stefan volumio[8591]: response: undefined Feb 07 05:53:07 volumio-stefan volumio[8591]: } Feb 07 05:53:07 volumio-stefan volumio[8591]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:53:08 volumio-stefan sudo[8852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 05:52' Feb 07 05:53:08 volumio-stefan sudo[8852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:08 volumio-stefan sudo[8852]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:08 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 05:53:08 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 05:53:08 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:08 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 05:53:08 volumio-stefan systemd[1]: volumio.service: Consumed 25.182s CPU time. Feb 07 05:53:08 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:53:08 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:53:08 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8319. Feb 07 05:53:09 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:53:09 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 05:53:09 volumio-stefan systemd[1]: volumio.service: Consumed 25.182s CPU time. Feb 07 05:53:09 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 05:53:09 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:53:10 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:10 volumio-stefan volumio[8864]: info: ----- Volumio3 ---- Feb 07 05:53:10 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:10 volumio-stefan volumio[8864]: info: ----- System startup ---- Feb 07 05:53:10 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:10 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 05:53:10 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:11 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:11 volumio-stefan go-librespot[8885]: go-librespot daemon starting... Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=debug msg="app state loaded" Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+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 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+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 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+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 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=info msg="zeroconf server listening on port 45705" Feb 07 05:53:11 volumio-stefan volumio[8864]: info: MYVOLUMIO Environment detected Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Plugin folders cleanup Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning into folder /volumio/app/plugins/ Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category audio_interface Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category miscellanea Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=debug msg="obtained new client token: AADBYEEi1LyhU2Xutcd2MNGsZGBnxNZ6ClFIQtVpBzfj9ZRUroTnn/G2/pzG+jG74c5qMM8XVKWD3lSaTNyIEsjGtihTIPNY308low9sYrDVFqcONN2pQ9QtZVre+8ox/7hYQmf0AIpvej4IdufM3F3bf9DkP05ZPkZqY9rhYhQ13ov3HEtv1EDbKme6yOD6Z8ej/2NozPFt6Ibqvmn5cOjgiyUnel90/rkNatAwVGIy4k5B0DEVBYg=" Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category music_service Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category plugins.json Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category system_controller Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category user_interface Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning into folder /data/plugins/ Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category music_service Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category system_controller Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Scanning category user_interface Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Plugin folders cleanup completed Feb 07 05:53:11 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:11 volumio-stefan volumio[8864]: info: ----- Core plugins startup ---- Feb 07 05:53:11 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Adding plugin upnp to MyMusic Plugins Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Loading plugins from folder /data/plugins/ Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Loading plugin "system"... Feb 07 05:53:11 volumio-stefan volumio[8864]: info: Loading plugin "appearance"... Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=debug msg="completed challenge" Feb 07 05:53:11 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:11+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:12 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:12+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:12 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:12+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:12 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:12+02:00" level=debug msg="completed challenge" Feb 07 05:53:12 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:12+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "network"... Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Refreshing Cached IP Addresses Feb 07 05:53:12 volumio-stefan sudo[8902]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 05:53:12 volumio-stefan sudo[8902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:12 volumio-stefan sudo[8902]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:12 volumio-stefan sudo[8904]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 05:53:12 volumio-stefan sudo[8904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "services"... Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "alsa_controller"... Feb 07 05:53:12 volumio-stefan sudo[8904]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:12 volumio-stefan sudo[8912]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 05:53:12 volumio-stefan sudo[8912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:12 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "wizard"... Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "networkfs"... Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Starting Udev Watcher for removable devices Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Ignoring mount for partition: boot Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Ignoring mount for partition: volumio Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Ignoring mount for partition: volumio_data Feb 07 05:53:12 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "volumio_command_line_client"... Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Plugin upnp is not enabled Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "my_music"... Feb 07 05:53:12 volumio-stefan volumio[8864]: info: Loading plugin "mpd"... Feb 07 05:53:13 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:13+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:53:13 volumio-stefan volumio[8864]: info: Plugin upnp_browser is not enabled Feb 07 05:53:13 volumio-stefan volumio[8864]: info: Loading plugin "alarm-clock"... Feb 07 05:53:13 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:13+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:13 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:13+02:00" level=debug msg="completed challenge" Feb 07 05:53:13 volumio-stefan volumio[8864]: info: Plugin airplay_emulation is not enabled Feb 07 05:53:13 volumio-stefan volumio[8864]: info: Loading plugin "last_100"... Feb 07 05:53:13 volumio-stefan volumio[8864]: info: Loading plugin "webradio"... Feb 07 05:53:13 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:13+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:13 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:13] [connect] Successful connection Feb 07 05:53:14 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:14+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:53:14 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:14+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:14 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:14+02:00" level=debug msg="completed challenge" Feb 07 05:53:14 volumio-stefan volumio[8864]: info: Loading plugin "i2s_dacs"... Feb 07 05:53:14 volumio-stefan volumio[8864]: info: Loading plugin "volumiodiscovery"... Feb 07 05:53:14 volumio-stefan volumio[8864]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:14 volumio-stefan volumio[8864]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:14 volumio-stefan volumio[8864]: *** WARNING *** For more information see Feb 07 05:53:14 volumio-stefan volumio[8864]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:14 volumio-stefan volumio[8864]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:14 volumio-stefan volumio[8864]: *** WARNING *** For more information see Feb 07 05:53:14 volumio-stefan node[8864]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:14 volumio-stefan node[8864]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:14 volumio-stefan node[8864]: *** WARNING *** For more information see Feb 07 05:53:14 volumio-stefan node[8864]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:14 volumio-stefan node[8864]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:14 volumio-stefan node[8864]: *** WARNING *** For more information see Feb 07 05:53:14 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:14+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:14 volumio-stefan volumio[8864]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 05:53:14 volumio-stefan volumio[8864]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 05:53:14 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:53:14 volumio-stefan volumio[8864]: info: Loading plugin "spop"... Feb 07 05:53:14 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25669. Feb 07 05:53:14 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:53:14 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:53:14 volumio-stefan upmpdcli[8935]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:53:14 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:14 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:53:15 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:53:15 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:15+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:15 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:15+02:00" level=debug msg="completed challenge" Feb 07 05:53:15 volumio-stefan volumio[8864]: info: Loading plugin "now_playing"... Feb 07 05:53:15 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:15+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:16 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:16+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "outputs"... Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "albumart"... Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Plugin example_plugin is not enabled Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "inputs"... Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "updater_comm"... Feb 07 05:53:16 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:16+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:16 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:16+02:00" level=debug msg="completed challenge" Feb 07 05:53:16 volumio-stefan sudo[8912]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Plugin mpdemulation is not enabled Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "rest_api"... Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "websocket"... Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Starting Socket.io Server version 1.7.4 Feb 07 05:53:16 volumio-stefan volumio[8864]: info: Loading plugin "backup_restore"... Feb 07 05:53:17 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:17 volumio-stefan go-librespot[8886]: time="2026-02-07T05:53:17+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 05:53:17 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:17 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:53:17 volumio-stefan volumio[8864]: info: Applying required configuration parameters for plugin backup_restore Feb 07 05:53:17 volumio-stefan volumio[8864]: info: Loading plugin "Systeminfo"... Feb 07 05:53:17 volumio-stefan volumio[8936]: Forking 3 albumart workers Feb 07 05:53:17 volumio-stefan volumio[8864]: info: Loading i18n strings for locale en Feb 07 05:53:17 volumio-stefan volumio[8864]: Updating browse sources language Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::initPlayerControls Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: Express server listening on port 3000 Feb 07 05:53:17 volumio-stefan volumio[8864]: [Metrics] WebUI: 7s 345.42ms Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreStateMachine::resetVolumioState Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreStateMachine::getcurrentVolume Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreStateMachine::pushState Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioPushState Feb 07 05:53:17 volumio-stefan volumio[8864]: info: Volumio Network Manager: Network status updated: 2 Feb 07 05:53:17 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770436393 101 Feb 07 05:53:17 volumio-stefan volumio[8864]: 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 05:53:17 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:17 volumio-stefan volumio[8864]: info: Reloading queue from file Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreStateMachine::setRepeat null single undefined Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreStateMachine::pushState Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioPushState Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreStateMachine::setRandom null Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreStateMachine::pushState Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioPushState Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Setting Device type: Raspberry PI Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Completed loading Core Plugins Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Preparing to generate the ALSA configuration file Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Discovery: Found device Volumio Stefan Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Asound.conf file unchanged, so no further update is needed Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Output device has changed, restarting MPD Feb 07 05:53:18 volumio-stefan volumio[8864]: info: ___________ START PLUGINS ___________ Feb 07 05:53:18 volumio-stefan sudo[8989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:53:18 volumio-stefan sudo[8989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:18 volumio-stefan volumio[8864]: info: ControllerMpd::onStart: Initializing MPD Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Creating MPD Configuration file Feb 07 05:53:18 volumio-stefan sudo[8987]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:53:18 volumio-stefan sudo[8987]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:18 volumio-stefan sudo[8987]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:53:18 volumio-stefan volumio[8864]: info: [1770436398210] CoreMusicLibrary::Adding element Last_100 Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:53:18 volumio-stefan sudo[8992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:53:18 volumio-stefan volumio[8864]: info: [1770436398218] CoreMusicLibrary::Adding element Webradio Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:53:18 volumio-stefan sudo[8992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:18 volumio-stefan sudo[8992]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:18 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Initializing BBC Radios Feb 07 05:53:18 volumio-stefan sudo[8995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:53:18 volumio-stefan sudo[8995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:18 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 05:53:18 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 05:53:18 volumio-stefan systemd[1]: mpd.service: Consumed 3.266s CPU time. Feb 07 05:53:18 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 05:53:18 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 05:53:18 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Creating Spotify config file Feb 07 05:53:18 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:18 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 05:53:18 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 05:53:18 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 05:53:18 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 05:53:18 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 05:53:18 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 05:53:18 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 05:53:18 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 05:53:18 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 05:53:18 volumio-stefan volumio[8946]: Starting albumart workers Feb 07 05:53:18 volumio-stefan sudo[9014]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 05:53:18 volumio-stefan sudo[9014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 05:53:18 volumio-stefan sudo[9014]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:18 volumio-stefan volumio[8948]: Starting albumart workers Feb 07 05:53:18 volumio-stefan volumio[8947]: Starting albumart workers Feb 07 05:53:18 volumio-stefan volumio[8864]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 05:53:18 volumio-stefan volumio[8864]: info: Volumio Calling Home Feb 07 05:53:19 volumio-stefan volumio[8864]: info: [now-playing] App is listening on port 4004. Feb 07 05:53:19 volumio-stefan volumio[8864]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 05:53:19 volumio-stefan volumio[8864]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:53:19 volumio-stefan volumio[8864]: info: Discovery: Found device Volumio Stefan Feb 07 05:53:19 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:19 volumio-stefan volumio[8864]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:19 volumio-stefan volumio[8864]: info: MPD Permissions set Feb 07 05:53:19 volumio-stefan volumio[8864]: info: MPD Permissions set Feb 07 05:53:19 volumio-stefan volumio[8864]: info: Volumio called home Feb 07 05:53:19 volumio-stefan volumio[8864]: info: Spotify config file written Feb 07 05:53:19 volumio-stefan sudo[9030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 05:53:19 volumio-stefan sudo[9030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:19 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:19 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:19 volumio-stefan go-librespot[9042]: go-librespot daemon starting... Feb 07 05:53:20 volumio-stefan sudo[9030]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=debug msg="app state loaded" Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:20 volumio-stefan volumio[8864]: 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 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:20 volumio-stefan volumio[8864]: info: No need to fix Spotify hosts Feb 07 05:53:20 volumio-stefan volumio[8864]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+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 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+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 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+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 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=info msg="zeroconf server listening on port 42663" Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:20 volumio-stefan volumio[8864]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=debug msg="obtained new client token: AACpmKzvvHfsxpEu7f3cr/A0pv1g5ZjtDPzsDYHjs6bvlA60IpU3zQYznF63Y7HqcqkYEnVS4FfIv4i+EAe/dEo5qwlVwcLcUlAqS8o3t/S+3MyzaEjbIMIjQEXU+3YPOdw1wP2XP70rLhPF7rMasg+C0BXfOFTtKCFTobO7wnIfL7j9uPd+BteR379kLYwGCDq/rboHsxfOuuaC65qURhhiIrnkDT06BvcXds3KPZzpKQdfvG7h5OY=" Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=debug msg="completed challenge" Feb 07 05:53:20 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:20+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:21 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:21+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:21 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:21+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:21 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:21+02:00" level=debug msg="completed challenge" Feb 07 05:53:21 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:21+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:21 volumio-stefan mpd[9016]: 2026-02-07T05:53:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 05:53:21 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 05:53:21 volumio-stefan sudo[8995]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:21 volumio-stefan sudo[8989]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:21 volumio-stefan volumio[8864]: info: Completed starting Core Plugins Feb 07 05:53:21 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:21 volumio-stefan volumio[8864]: info: ----- MyVolumio plugins startup ---- Feb 07 05:53:21 volumio-stefan volumio[8864]: info: ------------------------------------------- Feb 07 05:53:21 volumio-stefan volumio[8864]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 05:53:21 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:21+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:53:22 volumio-stefan volumio[8864]: error: MPD error: The expression evaluated to a falsy value: Feb 07 05:53:22 volumio-stefan volumio[8864]: assert.ok(self.idling) Feb 07 05:53:22 volumio-stefan volumio[8864]: error: The expression evaluated to a falsy value: Feb 07 05:53:22 volumio-stefan volumio[8864]: assert.ok(self.idling) Feb 07 05:53:22 volumio-stefan volumio[8864]: error: updateQueue error: null Feb 07 05:53:22 volumio-stefan volumio[8864]: info: MPD running with PID9016 Feb 07 05:53:22 volumio-stefan volumio[8864]: ,establishing connection Feb 07 05:53:22 volumio-stefan volumio[8864]: error: updateQueue error: null Feb 07 05:53:22 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:22+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:22 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:22+02:00" level=debug msg="completed challenge" Feb 07 05:53:22 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:22+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:22 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:22+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 05:53:22 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:22+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 05:53:23 volumio-stefan volumio[8864]: info: go-librespot daemon successfully initialized Feb 07 05:53:23 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:23+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:23 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:23+02:00" level=debug msg="completed challenge" Feb 07 05:53:23 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:23+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:24 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:24+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:53:25 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:25+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:25 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:25+02:00" level=debug msg="completed challenge" Feb 07 05:53:25 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:25+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:26 volumio-stefan volumio[8864]: info: Initializing connection to go-librespot Websocket Feb 07 05:53:26 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:26+02:00" level=debug msg="new websocket client" Feb 07 05:53:26 volumio-stefan volumio[8864]: info: Connection to go-librespot Websocket established Feb 07 05:53:26 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:26 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:26+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:26 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:26+02:00" level=debug msg="completed challenge" Feb 07 05:53:26 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:26+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:26 volumio-stefan go-librespot[9043]: time="2026-02-07T05:53:26+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 05:53:26 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:26 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:53:26 volumio-stefan volumio[8864]: info: Connection to go-librespot Websocket closed Feb 07 05:53:26 volumio-stefan volumio[8864]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 05:53:29 volumio-stefan volumio[8864]: info: Getting Spotify volume Feb 07 05:53:29 volumio-stefan volumio[8864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:53:29 volumio-stefan volumio[8864]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 05:53:29 volumio-stefan volumio[8864]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 05:53:29 volumio-stefan volumio[8864]: errno: -111, Feb 07 05:53:29 volumio-stefan volumio[8864]: code: 'ECONNREFUSED', Feb 07 05:53:29 volumio-stefan volumio[8864]: syscall: 'connect', Feb 07 05:53:29 volumio-stefan volumio[8864]: address: '127.0.0.1', Feb 07 05:53:29 volumio-stefan volumio[8864]: port: 9879, Feb 07 05:53:29 volumio-stefan volumio[8864]: response: undefined Feb 07 05:53:29 volumio-stefan volumio[8864]: } Feb 07 05:53:29 volumio-stefan volumio[8864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:53:29 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 07 05:53:29 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:29 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:29 volumio-stefan go-librespot[9094]: go-librespot daemon starting... Feb 07 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+02:00" level=debug msg="app state loaded" Feb 07 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+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 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+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 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+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 05:53:29 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:29+02:00" level=info msg="zeroconf server listening on port 33383" Feb 07 05:53:29 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25670. Feb 07 05:53:29 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:53:30 volumio-stefan sudo[9107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 05:52' Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="obtained new client token: AACqw9OP12n3XQMePGxXDxv6ROMqg49bLV6Rumg6Nedcor7Ou/XMiw3jredKK6ZOZc5OBgTTLqX3sTO8igiYYf3f0z3m4MxRR3PAU1tfeTb8ngBqLcuEzVxdHZubS+8rPrN3beS8PL3CB6tjf4T6ItDZ5hwD/DyrlH1wt3I4M1Z+Tfd/PhNDdHSoXp/e87NwuqQNhJO8gFtLJqXiPT75nkTLbnqYfVTE6SE7IXg3QAb0xC4aO13ihOY=" Feb 07 05:53:30 volumio-stefan sudo[9107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:30 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:53:30 volumio-stefan upmpdcli[9104]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:53:30 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:30 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+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 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:30 volumio-stefan sudo[9107]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="completed challenge" Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:30 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 05:53:30 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 05:53:30 volumio-stefan systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:30 volumio-stefan systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 05:53:30 volumio-stefan systemd[1]: volumio.service: Consumed 22.044s CPU time. Feb 07 05:53:30 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:53:30 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=debug msg="completed challenge" Feb 07 05:53:30 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:30+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:30 volumio-stefan systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8320. Feb 07 05:53:31 volumio-stefan systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 05:53:31 volumio-stefan systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 05:53:31 volumio-stefan systemd[1]: volumio.service: Consumed 22.044s CPU time. Feb 07 05:53:31 volumio-stefan systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 05:53:31 volumio-stefan systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 05:53:31 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:31+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 07 05:53:31 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:31+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:31 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:31+02:00" level=debug msg="completed challenge" Feb 07 05:53:31 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:31+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:32 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:32+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 05:53:32 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:32+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:32 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:32+02:00" level=debug msg="completed challenge" Feb 07 05:53:32 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:32 volumio-stefan volumio[9126]: info: ----- Volumio3 ---- Feb 07 05:53:32 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:32 volumio-stefan volumio[9126]: info: ----- System startup ---- Feb 07 05:53:32 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:32 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:32+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:33 volumio-stefan volumio[9126]: info: MYVOLUMIO Environment detected Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Plugin folders cleanup Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning into folder /volumio/app/plugins/ Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category audio_interface Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category miscellanea Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category music_service Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category plugins.json Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category system_controller Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category user_interface Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning into folder /data/plugins/ Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category music_service Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category system_controller Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Scanning category user_interface Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Plugin folders cleanup completed Feb 07 05:53:33 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:33 volumio-stefan volumio[9126]: info: ----- Core plugins startup ---- Feb 07 05:53:33 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Adding plugin upnp to MyMusic Plugins Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Loading plugins from folder /data/plugins/ Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Loading plugin "system"... Feb 07 05:53:33 volumio-stefan volumio[9126]: info: Loading plugin "appearance"... Feb 07 05:53:33 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:33+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:53:33 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:33+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:33 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:33+02:00" level=debug msg="completed challenge" Feb 07 05:53:34 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:34+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "network"... Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Refreshing Cached IP Addresses Feb 07 05:53:34 volumio-stefan sudo[9155]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 05:53:34 volumio-stefan sudo[9155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:34 volumio-stefan sudo[9157]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 05:53:34 volumio-stefan sudo[9157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "services"... Feb 07 05:53:34 volumio-stefan sudo[9155]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:34 volumio-stefan sudo[9157]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "alsa_controller"... Feb 07 05:53:34 volumio-stefan sudo[9165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 05:53:34 volumio-stefan sudo[9165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:34 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "wizard"... Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "networkfs"... Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Starting Udev Watcher for removable devices Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Ignoring mount for partition: boot Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Ignoring mount for partition: volumio Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Ignoring mount for partition: volumio_data Feb 07 05:53:34 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "volumio_command_line_client"... Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Plugin upnp is not enabled Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "my_music"... Feb 07 05:53:34 volumio-stefan volumio[9126]: info: Loading plugin "mpd"... Feb 07 05:53:34 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:34+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:35 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:35+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:35 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:35+02:00" level=debug msg="completed challenge" Feb 07 05:53:35 volumio-stefan volumio[9126]: info: Plugin upnp_browser is not enabled Feb 07 05:53:35 volumio-stefan volumio[9126]: info: Loading plugin "alarm-clock"... Feb 07 05:53:35 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:35+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:35 volumio-stefan go-librespot[9095]: time="2026-02-07T05:53:35+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 05:53:35 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:35 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:53:35 volumio-stefan volumio[9126]: info: Plugin airplay_emulation is not enabled Feb 07 05:53:35 volumio-stefan volumio[9126]: info: Loading plugin "last_100"... Feb 07 05:53:35 volumio-stefan volumio[9126]: info: Loading plugin "webradio"... Feb 07 05:53:35 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:35] [connect] Successful connection Feb 07 05:53:36 volumio-stefan volumio[9126]: info: Loading plugin "i2s_dacs"... Feb 07 05:53:36 volumio-stefan volumio[9126]: info: Loading plugin "volumiodiscovery"... Feb 07 05:53:36 volumio-stefan volumio[9126]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:36 volumio-stefan volumio[9126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:36 volumio-stefan volumio[9126]: *** WARNING *** For more information see Feb 07 05:53:36 volumio-stefan volumio[9126]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:36 volumio-stefan volumio[9126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:36 volumio-stefan volumio[9126]: *** WARNING *** For more information see Feb 07 05:53:36 volumio-stefan node[9126]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:36 volumio-stefan node[9126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:36 volumio-stefan node[9126]: *** WARNING *** For more information see Feb 07 05:53:36 volumio-stefan node[9126]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 05:53:36 volumio-stefan node[9126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 05:53:36 volumio-stefan node[9126]: *** WARNING *** For more information see Feb 07 05:53:36 volumio-stefan volumio[9126]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 05:53:36 volumio-stefan volumio[9126]: info: Discovery: Started advertising with name: Volumio Stefan Feb 07 05:53:36 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 05:53:36 volumio-stefan volumio[9126]: info: Loading plugin "spop"... Feb 07 05:53:37 volumio-stefan volumio[9126]: info: Loading plugin "now_playing"... Feb 07 05:53:38 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 07 05:53:38 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:38 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:38 volumio-stefan go-librespot[9187]: go-librespot daemon starting... Feb 07 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+02:00" level=debug msg="app state loaded" Feb 07 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "outputs"... Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "albumart"... Feb 07 05:53:38 volumio-stefan sudo[9165]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Plugin example_plugin is not enabled Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "inputs"... Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "updater_comm"... Feb 07 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+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 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+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 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+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 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+02:00" level=info msg="zeroconf server listening on port 43955" Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Plugin mpdemulation is not enabled Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "rest_api"... Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "websocket"... Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Starting Socket.io Server version 1.7.4 Feb 07 05:53:38 volumio-stefan volumio[9126]: info: Loading plugin "backup_restore"... Feb 07 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+02:00" level=debug msg="obtained new client token: AADQoBEB7dbGVTHY4Lh4aWu6Mv2MgxA+uckuzIblsE7Z3fV4UNX+y31UhTdpeU763JboY922Z4GjNdTfXSefotCyicpNwbNwIOy1GAkPOEF4t28atp5PxyTwWad8Im1XckZ3XmflWXIFCRw4Z/RUMsf9zNEmr4ePTgboi4A+hUZgmA8D8o1Sd6qneBHJfM4loKRCq4GiYGsgQMjvkDf+WMnPMnO9aJ/J3ACXYBKvR2+gEW5Uq3bVsDw=" Feb 07 05:53:38 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:38+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=debug msg="completed challenge" Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Applying required configuration parameters for plugin backup_restore Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Loading plugin "Systeminfo"... Feb 07 05:53:39 volumio-stefan volumio[9197]: Forking 3 albumart workers Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Loading i18n strings for locale en Feb 07 05:53:39 volumio-stefan volumio[9126]: Updating browse sources language Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::initPlayerControls Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: Express server listening on port 3000 Feb 07 05:53:39 volumio-stefan volumio[9126]: [Metrics] WebUI: 7s 360.68ms Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::resetVolumioState Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::getcurrentVolume Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::pushState Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioPushState Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=debug msg="completed challenge" Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Volumio Network Manager: Network status updated: 2 Feb 07 05:53:39 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:39+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:39 volumio-stefan volumio-remote-updater[658]: [2026-02-07 05:53:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770436415 101 Feb 07 05:53:39 volumio-stefan volumio[9126]: 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 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Reloading queue from file Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::setRepeat null single undefined Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::pushState Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioPushState Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::setRandom null Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreStateMachine::pushState Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:39 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioPushState Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Setting Device type: Raspberry PI Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Completed loading Core Plugins Feb 07 05:53:39 volumio-stefan volumio[9126]: info: Preparing to generate the ALSA configuration file Feb 07 05:53:40 volumio-stefan volumio[9126]: info: Asound.conf file unchanged, so no further update is needed Feb 07 05:53:40 volumio-stefan volumio[9126]: info: Output device has changed, restarting MPD Feb 07 05:53:40 volumio-stefan volumio[9126]: info: ___________ START PLUGINS ___________ Feb 07 05:53:40 volumio-stefan sudo[9247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:53:40 volumio-stefan sudo[9247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:40 volumio-stefan sudo[9247]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:40 volumio-stefan volumio[9126]: info: ControllerMpd::onStart: Initializing MPD Feb 07 05:53:40 volumio-stefan volumio[9126]: info: Creating MPD Configuration file Feb 07 05:53:40 volumio-stefan sudo[9249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:53:40 volumio-stefan volumio[9126]: info: [1770436420150] CoreMusicLibrary::Adding element Last_100 Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:53:40 volumio-stefan sudo[9249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 05:53:40 volumio-stefan volumio[9126]: info: [1770436420161] CoreMusicLibrary::Adding element Webradio Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:53:40 volumio-stefan sudo[9252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 05:53:40 volumio-stefan sudo[9252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:40 volumio-stefan volumio[9126]: info: Initializing BBC Radios Feb 07 05:53:40 volumio-stefan sudo[9252]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:40 volumio-stefan sudo[9254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 05:53:40 volumio-stefan sudo[9254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:40 volumio-stefan systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:40 volumio-stefan systemd[1]: mpd.service: Deactivated successfully. Feb 07 05:53:40 volumio-stefan systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 05:53:40 volumio-stefan systemd[1]: mpd.service: Consumed 3.287s CPU time. Feb 07 05:53:40 volumio-stefan volumio[9126]: info: Creating Spotify config file Feb 07 05:53:40 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:40 volumio-stefan systemd[1]: mpd.socket: Deactivated successfully. Feb 07 05:53:40 volumio-stefan systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 05:53:40 volumio-stefan systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 05:53:40 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:40+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:53:40 volumio-stefan systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 05:53:40 volumio-stefan systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 05:53:40 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:40+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:40 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:40+02:00" level=debug msg="completed challenge" Feb 07 05:53:40 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:40+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:40 volumio-stefan volumio[9207]: Starting albumart workers Feb 07 05:53:40 volumio-stefan sudo[9272]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 05:53:40 volumio-stefan sudo[9272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 05:53:40 volumio-stefan sudo[9272]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:40 volumio-stefan volumio[9126]: info: [now-playing] ConfigUpdater: config is up to date. Feb 07 05:53:40 volumio-stefan volumio[9126]: info: Volumio Calling Home Feb 07 05:53:40 volumio-stefan volumio[9209]: Starting albumart workers Feb 07 05:53:41 volumio-stefan volumio[9208]: Starting albumart workers Feb 07 05:53:41 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:41+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:53:41 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:41+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:41 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:41+02:00" level=debug msg="completed challenge" Feb 07 05:53:41 volumio-stefan volumio[9126]: info: [now-playing] App is listening on port 4004. Feb 07 05:53:41 volumio-stefan volumio[9126]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 07 05:53:41 volumio-stefan go-librespot[9188]: time="2026-02-07T05:53:41+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:41 volumio-stefan volumio[9126]: info: Discovery: adding 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:53:41 volumio-stefan volumio[9126]: info: Discovery: Found device Volumio Stefan Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:41 volumio-stefan volumio[9126]: info: MPD Permissions set Feb 07 05:53:41 volumio-stefan volumio[9126]: info: MPD Permissions set Feb 07 05:53:41 volumio-stefan volumio[9126]: info: Discovery: this is already registered, 9fd4730c-d5cc-4b0d-8799-894bfe737c6c Feb 07 05:53:41 volumio-stefan volumio[9126]: info: Discovery: Found device Volumio Stefan Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:41 volumio-stefan volumio[9126]: info: Volumio called home Feb 07 05:53:41 volumio-stefan volumio[9126]: info: Spotify config file written Feb 07 05:53:41 volumio-stefan sudo[9287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 05:53:41 volumio-stefan sudo[9287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:41 volumio-stefan systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 05:53:41 volumio-stefan systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 05:53:41 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:41 volumio-stefan volumio[9126]: 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 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:41 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:41 volumio-stefan go-librespot[9289]: go-librespot daemon starting... Feb 07 05:53:41 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan sudo[9287]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 05:53:42 volumio-stefan volumio[9126]: info: No need to fix Spotify hosts Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=debug msg="app state loaded" Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:42 volumio-stefan volumio[9126]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+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 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+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 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+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 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=info msg="zeroconf server listening on port 37423" Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:42 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=debug msg="obtained new client token: AAAHs1TbtxLUGhbNUQWu3bq4ljT++PNiqA4V5xtGcaAOzKOA0xmMNYo+T1fKOz+VEnf/LfmSVs88f/hOnGDaX/kPGL1vuQ/FMVShvLh4KBJvg6IFbbL1UpPWnNrKzk5AY9amO/LGL7S/EzNfpL9YXogrSGdUAG5xfJSxAgkzhwOu+Tw/cbV5Di/C7d3mHBLmAbp8R/Cz+7MTmma+jWrMmg8UgfKwOdQFMX3syXDsZNuTtL7ZIMwsGjw=" Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=debug msg="completed challenge" Feb 07 05:53:42 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:42+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:43 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:43+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:43 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:43+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:43 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:43+02:00" level=debug msg="completed challenge" Feb 07 05:53:43 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:43+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:43 volumio-stefan mpd[9274]: 2026-02-07T05:53:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 05:53:43 volumio-stefan systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 05:53:43 volumio-stefan sudo[9249]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:43 volumio-stefan sudo[9254]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:43 volumio-stefan volumio[9126]: info: Completed starting Core Plugins Feb 07 05:53:43 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:43 volumio-stefan volumio[9126]: info: ----- MyVolumio plugins startup ---- Feb 07 05:53:43 volumio-stefan volumio[9126]: info: ------------------------------------------- Feb 07 05:53:43 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 05:53:44 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:44+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 05:53:44 volumio-stefan volumio[9126]: error: MPD error: The expression evaluated to a falsy value: Feb 07 05:53:44 volumio-stefan volumio[9126]: assert.ok(self.idling) Feb 07 05:53:44 volumio-stefan volumio[9126]: error: The expression evaluated to a falsy value: Feb 07 05:53:44 volumio-stefan volumio[9126]: assert.ok(self.idling) Feb 07 05:53:44 volumio-stefan volumio[9126]: error: updateQueue error: null Feb 07 05:53:44 volumio-stefan volumio[9126]: info: MPD running with PID9274 Feb 07 05:53:44 volumio-stefan volumio[9126]: ,establishing connection Feb 07 05:53:44 volumio-stefan volumio[9126]: error: updateQueue error: null Feb 07 05:53:44 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:44+02:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 07 05:53:44 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:44+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:44 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:44+02:00" level=debug msg="completed challenge" Feb 07 05:53:44 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:44+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:44 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 07 05:53:45 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:45+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:45 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:45+02:00" level=debug msg="completed challenge" Feb 07 05:53:45 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:45+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:45 volumio-stefan systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25671. Feb 07 05:53:45 volumio-stefan systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:53:45 volumio-stefan systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 07 05:53:45 volumio-stefan upmpdcli[9341]: Could not open config: /tmp/upmpdcli.conf Feb 07 05:53:45 volumio-stefan systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:45 volumio-stefan systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 07 05:53:45 volumio-stefan volumio[9126]: info: go-librespot daemon successfully initialized Feb 07 05:53:45 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:45+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:53:46 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:46+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:46 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:46+02:00" level=debug msg="completed challenge" Feb 07 05:53:46 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:46+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:46 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:46+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:47 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:47+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:47 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:47+02:00" level=debug msg="completed challenge" Feb 07 05:53:47 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:47+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:47 volumio-stefan go-librespot[9295]: time="2026-02-07T05:53:47+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 05:53:47 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:47 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:53:48 volumio-stefan volumio[9126]: info: Initializing connection to go-librespot Websocket Feb 07 05:53:48 volumio-stefan volumio[9126]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 05:53:48 volumio-stefan volumio[9126]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 05:53:50 volumio-stefan systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 05:53:50 volumio-stefan systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:50 volumio-stefan systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 05:53:50 volumio-stefan go-librespot[9342]: go-librespot daemon starting... Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=info msg="running go-librespot 0.6.2" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=debug msg="app state loaded" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+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 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+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 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+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 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=info msg="zeroconf server listening on port 35577" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=debug msg="obtained new client token: AABKG7kD95OnyGFcZDntKy7NvHSTkE/5khdJmz2J3yL6Tjmhoqn81fpBCq8PiAcOvGtwAANpOfwLkKabcI8uk7pMJJz/sdaQh/mDldI51UfUej9GBzmEIEXGTrJntlu2d5B/el40LWIRuaHuFgPZsNKex5F9lJF3A6edhCKEC0TNGVp5KdArG/uSt8mWytiddKrmplDuSltAYWR37LH6fT8CdX1hsqrr5X0uVDCxubYtD/UGSWSbGTM=" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=debug msg="completed challenge" Feb 07 05:53:50 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:50+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:51 volumio-stefan volumio[9126]: info: Initializing connection to go-librespot Websocket Feb 07 05:53:51 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:51+02:00" level=debug msg="new websocket client" Feb 07 05:53:51 volumio-stefan volumio[9126]: info: Connection to go-librespot Websocket established Feb 07 05:53:51 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:51+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 07 05:53:51 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:51+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:51 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:51+02:00" level=debug msg="completed challenge" Feb 07 05:53:51 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:51+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:52 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:52+02:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 07 05:53:52 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:52+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:52 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:52+02:00" level=debug msg="completed challenge" Feb 07 05:53:52 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:52+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 05:53:52 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 05:53:52 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:52+02:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 07 05:53:53 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:53+02:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 07 05:53:53 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:53+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:53 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:53+02:00" level=debug msg="completed challenge" Feb 07 05:53:53 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 05:53:53 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 05:53:53 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:53 volumio-stefan volumio[9126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 05:53:53 volumio-stefan volumio[9126]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 05:53:53 volumio-stefan volumio[9126]: info: MyVolumio login type: Token Feb 07 05:53:53 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 05:53:53 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 05:53:53 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:53+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:54 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 05:53:54 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 05:53:54 volumio-stefan volumio[9126]: info: Streaming services startup Feb 07 05:53:54 volumio-stefan volumio[9126]: info: Starting Streaming Daemon Feb 07 05:53:54 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:54+02:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 05:53:54 volumio-stefan sudo[9353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 05:53:54 volumio-stefan sudo[9353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 05:53:54 volumio-stefan volumio[9126]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 05:53:54 volumio-stefan sudo[9353]: pam_unix(sudo:session): session closed for user root Feb 07 05:53:54 volumio-stefan volumio[9126]: error: Cannot start Volumio Streaming Daemon Feb 07 05:53:54 volumio-stefan volumio[9126]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 05:53:54 volumio-stefan volumio[9126]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 05:53:54 volumio-stefan volumio[9126]: info: Getting Spotify volume Feb 07 05:53:54 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:54+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:54 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:54+02:00" level=debug msg="completed challenge" Feb 07 05:53:54 volumio-stefan volumio[9126]: 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 05:53:54 volumio-stefan volumio[9126]: info: CoreCommandRouter::volumioGetState Feb 07 05:53:54 volumio-stefan volumio[9126]: info: CorePlayQueue::getTrack 0 Feb 07 05:53:54 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:54+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:54 volumio-stefan volumio[9126]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 05:53:55 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:55+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 07 05:53:55 volumio-stefan volumio[9126]: info: MyVolumio token set successfully Feb 07 05:53:55 volumio-stefan volumio[9126]: info: MYVOLUMIO: Adding device Feb 07 05:53:55 volumio-stefan volumio[9126]: info: MYVOLUMIO: Evaluating Server Feb 07 05:53:55 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:55+02:00" level=debug msg="completed keyexchange" Feb 07 05:53:55 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:55+02:00" level=debug msg="completed challenge" Feb 07 05:53:55 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:55+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 07 05:53:55 volumio-stefan go-librespot[9343]: time="2026-02-07T05:53:55+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 05:53:55 volumio-stefan systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 05:53:55 volumio-stefan systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 05:53:55 volumio-stefan volumio[9126]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:53:55 volumio-stefan volumio[9126]: Error: socket hang up Feb 07 05:53:55 volumio-stefan volumio[9126]: at connResetException (node:internal/errors:720:14) Feb 07 05:53:55 volumio-stefan volumio[9126]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 05:53:55 volumio-stefan volumio[9126]: at Socket.emit (node:events:526:35) Feb 07 05:53:55 volumio-stefan volumio[9126]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 05:53:55 volumio-stefan volumio[9126]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 05:53:55 volumio-stefan volumio[9126]: code: 'ECONNRESET', Feb 07 05:53:55 volumio-stefan volumio[9126]: response: undefined Feb 07 05:53:55 volumio-stefan volumio[9126]: } Feb 07 05:53:55 volumio-stefan volumio[9126]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 05:53:56 volumio-stefan sudo[9390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 05:52' Feb 07 05:53:56 volumio-stefan sudo[9390]: 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"