Feb 17 09:13:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 09:13:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:01 volumio go-librespot[2828]: go-librespot daemon starting... Feb 17 09:13:01 volumio go-librespot[2829]: time="2026-02-17T09:13:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:01 volumio go-librespot[2829]: time="2026-02-17T09:13:01+07:00" level=debug msg="app state loaded" Feb 17 09:13:01 volumio go-librespot[2829]: time="2026-02-17T09:13:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=info msg="zeroconf server listening on port 42561" Feb 17 09:13:02 volumio volumio[2739]: info: Loading plugin "ytmusic"... Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="obtained new client token: AADThYzzs9xVtOZ9TdXqZuXYs4mu0DqQlevjn9XStpz9ql3eQ4klZFyMZ2lmAYWWNLRCheFIMTj/sFBZOMk+hbS2BPVpWEykHatH+MSN5gjQ+RfUnavg7z/MdKGNUbQXyYwHBF8jIq6CNQt0mB63D0HXE+koET/M599VTZEsaGujE3vn3PC5MDPUUQJQOOcokwPe1gefPxu9BIiPwu9UnoiBNv9WoS2aoRJtKU9/8J6J021iBfvAM9xNrA==" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07:00" level=debug msg="completed challenge" Feb 17 09:13:02 volumio go-librespot[2829]: time="2026-02-17T09:13:02+07: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 17 09:13:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:03 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:03] [connect] Successful connection Feb 17 09:13:03 volumio volumio[2739]: info: Loading plugin "outputs"... Feb 17 09:13:03 volumio volumio[2739]: info: Loading plugin "albumart"... Feb 17 09:13:03 volumio volumio[2739]: info: Plugin example_plugin is not enabled Feb 17 09:13:03 volumio volumio[2739]: info: Loading plugin "inputs"... Feb 17 09:13:03 volumio volumio[2739]: info: Loading plugin "updater_comm"... Feb 17 09:13:03 volumio volumio[2739]: info: Plugin mpdemulation is not enabled Feb 17 09:13:03 volumio volumio[2739]: info: Loading plugin "rest_api"... Feb 17 09:13:03 volumio volumio[2739]: info: Loading plugin "websocket"... Feb 17 09:13:04 volumio volumio[2739]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:13:04 volumio volumio[2739]: info: Loading plugin "RoonBridge"... Feb 17 09:13:04 volumio volumio[2739]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 09:13:04 volumio volumio[2739]: info: Loading i18n strings for locale en Feb 17 09:13:04 volumio volumio[2739]: Updating browse sources language Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:04 volumio volumio[2850]: Forking 3 albumart workers Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::initPlayerControls Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:13:04 volumio volumio[2739]: Express server listening on port 3000 Feb 17 09:13:04 volumio volumio[2739]: [Metrics] WebUI: 16s 276.58ms Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::resetVolumioState Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::getcurrentVolume Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:13:05 volumio sudo[2895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:13:05 volumio sudo[2895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:05 volumio sudo[2897]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:13:05 volumio sudo[2897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:05 volumio sudo[2897]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:05 volumio sudo[2895]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:05 volumio volumio[2739]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:13:05 volumio volumio[2739]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::pushState Feb 17 09:13:05 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::updateTrackBlock Feb 17 09:13:05 volumio volumio[2739]: info: CorePlayQueue::getTrackBlock Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:13:05 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771294383 101 Feb 17 09:13:05 volumio volumio[2739]: 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 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:05 volumio volumio[2739]: info: Reloading queue from file Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::pushState Feb 17 09:13:05 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::setRandom null Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::pushState Feb 17 09:13:05 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:05 volumio volumio[2739]: info: Setting Device type: Raspberry PI Feb 17 09:13:05 volumio volumio[2739]: info: Completed loading Core Plugins Feb 17 09:13:05 volumio volumio[2739]: info: Preparing to generate the ALSA configuration file Feb 17 09:13:05 volumio volumio[2739]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:13:05 volumio volumio[2739]: info: CoreStateMachine::pushState Feb 17 09:13:05 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:05 volumio volumio[2739]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 09:13:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:06 volumio volumio[2739]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:13:06 volumio volumio[2739]: info: Output device has changed, restarting MPD Feb 17 09:13:06 volumio volumio[2739]: info: Output device has changed, restarting Shairport Sync Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:06 volumio sudo[2912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:13:06 volumio sudo[2912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:06 volumio go-librespot[2913]: go-librespot daemon starting... Feb 17 09:13:06 volumio sudo[2917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:13:06 volumio sudo[2917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:06 volumio go-librespot[2920]: time="2026-02-17T09:13:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:06 volumio go-librespot[2920]: time="2026-02-17T09:13:06+07:00" level=debug msg="app state loaded" Feb 17 09:13:06 volumio go-librespot[2920]: time="2026-02-17T09:13:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:06 volumio sudo[2915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:13:06 volumio sudo[2915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:06 volumio sudo[2915]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:06 volumio volumio[2739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:13:06 volumio volumio[2739]: info: ___________ START PLUGINS ___________ Feb 17 09:13:06 volumio volumio[2739]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:13:06 volumio volumio[2739]: info: Creating MPD Configuration file Feb 17 09:13:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:06 volumio volumio[2739]: info: [1771294386407] CoreMusicLibrary::Adding element Media Servers Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:06 volumio sudo[2912]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:06 volumio volumio[2739]: info: UPNP Browser: Client initialized successfully Feb 17 09:13:06 volumio sudo[2934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:13:06 volumio sudo[2934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:06 volumio sudo[2932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:13:06 volumio sudo[2932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:06 volumio sudo[2932]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:06 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:13:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:13:06 volumio systemd[1]: mpd.service: Consumed 7.055s CPU time. Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:13:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:13:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:13:06 volumio volumio[2739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:13:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:13:06 volumio volumio[2739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:06 volumio volumio[2739]: info: [1771294386777] CoreMusicLibrary::Adding element Last_100 Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:06 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:13:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:13:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:13:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:13:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:06 volumio volumio[2739]: info: [1771294386815] CoreMusicLibrary::Adding element Webradio Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:13:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:13:06 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:13:06 volumio volumio[2739]: info: Initializing BBC Radios Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=info msg="zeroconf server listening on port 45929" Feb 17 09:13:07 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:13:07 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:07 volumio volumio[2739]: info: Creating Spotify config file Feb 17 09:13:07 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="obtained new client token: AADvcGdXHCQQuXOqk62FIuEpSpPAurSckagYT1rYTmN2cSzhB01Nt5fmOLmilC4TunUNA0b7A07rKj/uDK0Wb2e2XGNqrmdiugd0XZX0D5WzRTQVNX9S0HYIeSfn8bTggc3GjkP4c8nbz6Xm+fAK+0DbKN5nnB59hJFstykySsZD78ftlUJN6utpUWl4+tJbCyMtB5Gapbx67AS04MMGt49RSPYFitWD1ky8fIYrOu3HACE2gNgur5s=" Feb 17 09:13:07 volumio sudo[2949]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:13:07 volumio sudo[2949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:13:07 volumio sudo[2949]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07:00" level=debug msg="completed challenge" Feb 17 09:13:07 volumio go-librespot[2920]: time="2026-02-17T09:13:07+07: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 17 09:13:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:08 volumio volumio[2862]: Starting albumart workers Feb 17 09:13:08 volumio volumio[2739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:08 volumio volumio[2739]: info: [1771294388302] CoreMusicLibrary::Adding element YouTube Music Feb 17 09:13:08 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:08 volumio volumio[2739]: Cannot find translation for source YouTube Music Feb 17 09:13:08 volumio volumio[2739]: info: Volumio Calling Home Feb 17 09:13:08 volumio volumio[2860]: Starting albumart workers Feb 17 09:13:08 volumio sudo[2966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 09:13:08 volumio sudo[2966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:08 volumio volumio[2861]: Starting albumart workers Feb 17 09:13:08 volumio sudo[2966]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:09 volumio volumio[2739]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:13:09 volumio volumio[2739]: info: Discovery: Found device Volumio Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:09 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:09 volumio volumio[2739]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:13:09 volumio volumio[2739]: info: Discovery: Found device Volumio Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:09 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:09 volumio volumio[2739]: info: MPD Permissions set Feb 17 09:13:09 volumio volumio[2739]: info: MPD Permissions set Feb 17 09:13:09 volumio volumio[2739]: info: Upmpdcli Daemon Started Feb 17 09:13:09 volumio volumio[2739]: info: Spotify config file written Feb 17 09:13:09 volumio sudo[2972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:13:09 volumio sudo[2972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:09 volumio volumio[2739]: 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 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:09 volumio go-librespot[2982]: go-librespot daemon starting... Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:09 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:09 volumio sudo[2972]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:09 volumio volumio[2739]: info: No need to fix Spotify hosts Feb 17 09:13:09 volumio go-librespot[2991]: time="2026-02-17T09:13:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:09 volumio go-librespot[2991]: time="2026-02-17T09:13:09+07:00" level=debug msg="app state loaded" Feb 17 09:13:10 volumio go-librespot[2991]: time="2026-02-17T09:13:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:10 volumio volumio[2739]: info: Volumio called home Feb 17 09:13:10 volumio go-librespot[2991]: time="2026-02-17T09:13:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:10 volumio go-librespot[2991]: time="2026-02-17T09:13:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:10 volumio go-librespot[2991]: time="2026-02-17T09:13:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:10 volumio go-librespot[2991]: time="2026-02-17T09:13:10+07:00" level=info msg="zeroconf server listening on port 34681" Feb 17 09:13:10 volumio volumio[2739]: info: Starting Shairport Sync Feb 17 09:13:10 volumio go-librespot[2991]: time="2026-02-17T09:13:10+07:00" level=debug msg="obtained new client token: AAARVDi790FHdzpcmNgEiN1StsLShcWfJJkG5jrCrQ7fVRVntczBdmw9/SrllSIQ47tp03m8emXlEZ3eOe2OfVB7VrIaCqlKZbxwPItE1Dhs066hCZNGRaSE0Z12OykCNn523pP+PmMz29zpXOQ1kiqkAOrGLftDvOuIYzp6BPyF0Eh1pXCwLxH1XbHveWQPTpCiXSBMEX2fWkS8FDpxITt+loXSUGfa0XXO4uCPfeNykHFP3KWBDT7p+Q==" Feb 17 09:13:10 volumio volumio[2739]: info: Starting Shairport Sync Feb 17 09:13:10 volumio volumio[2739]: info: Starting Shairport Sync Feb 17 09:13:11 volumio sudo[3011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:13:11 volumio sudo[3011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:11 volumio sudo[3013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:13:11 volumio sudo[3013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:11 volumio go-librespot[2991]: time="2026-02-17T09:13:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:11 volumio sudo[3015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:13:11 volumio sudo[3015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:11 volumio go-librespot[2991]: time="2026-02-17T09:13:11+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:11 volumio go-librespot[2991]: time="2026-02-17T09:13:11+07:00" level=debug msg="completed challenge" Feb 17 09:13:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:13:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:13:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:13:11 volumio systemd[1]: shairport-sync.service: Consumed 2.222s CPU time. Feb 17 09:13:11 volumio volumio[2739]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:13:11 volumio volumio[2739]: SPOTIFY: BQAwPU3v5rIj4EII8sg8m6xtCyfbH3E-oMJ98bvjmri9V2zlSBwoSKivc9RgchL2LUYw9M-fNagVJhFZv12SSvO2ZWKMiC2-OLlnAvNifOrBT9OYr67lxt2q4EvVZMLGtdWAkMsrCI1P7ccRRbdTuyuLrPfatjp6ZzuCQwDbTU04GSlkhR0EYXDjH1nTTBtP-YqR4MBnNN6OL3aBUevbbwi5WcO9obcckPktfvDwrMd08OXCcD27NHabHbY1u5dxslJgkmZscPCHe57gmRhc2bq7qwjdFX2oWTGK118bOncCj_0nda0-047H Feb 17 09:13:11 volumio go-librespot[2991]: time="2026-02-17T09:13:11+07: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 17 09:13:11 volumio volumio[2739]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:13:11 volumio volumio[2739]: info: New Spotify access token = BQAwPU3v5rIj4EII8sg8m6xtCyfbH3E-oMJ98bvjmri9V2zlSBwoSKivc9RgchL2LUYw9M-fNagVJhFZv12SSvO2ZWKMiC2-OLlnAvNifOrBT9OYr67lxt2q4EvVZMLGtdWAkMsrCI1P7ccRRbdTuyuLrPfatjp6ZzuCQwDbTU04GSlkhR0EYXDjH1nTTBtP-YqR4MBnNN6OL3aBUevbbwi5WcO9obcckPktfvDwrMd08OXCcD27NHabHbY1u5dxslJgkmZscPCHe57gmRhc2bq7qwjdFX2oWTGK118bOncCj_0nda0-047H Feb 17 09:13:11 volumio volumio[2739]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:13:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:13:11 volumio sudo[3011]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:11 volumio sudo[3013]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:11 volumio sudo[3015]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:11 volumio volumio[2739]: info: Shairport-Sync Started Feb 17 09:13:11 volumio volumio[2739]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:13:11 volumio volumio[2739]: info: Shairport-Sync Started Feb 17 09:13:11 volumio volumio[2739]: info: Shairport-Sync Started Feb 17 09:13:11 volumio volumio[2739]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:11 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:11 volumio volumio[2739]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 09:13:11 volumio volumio[2739]: info: Spotify Successfully logged in Feb 17 09:13:11 volumio volumio[2739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:11 volumio volumio[2739]: info: [1771294391898] CoreMusicLibrary::Adding element Spotify Feb 17 09:13:11 volumio volumio[2739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:11 volumio volumio[2739]: Cannot find translation for source YouTube Music Feb 17 09:13:11 volumio volumio[2739]: Cannot find translation for source Spotify Feb 17 09:13:12 volumio volumio[2739]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 09:13:12 volumio volumio[2739]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:13:12 volumio volumio[2739]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:13:12 volumio volumio[2739]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:12 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:12 volumio volumio[2739]: info: CoreStateMachine::pushState Feb 17 09:13:12 volumio volumio[2739]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:12 volumio volumio[2739]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:13 volumio volumio[2739]: info: go-librespot daemon successfully initialized Feb 17 09:13:14 volumio mpd[2964]: 2026-02-17T09:13:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:13:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:13:14 volumio sudo[2934]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:14 volumio sudo[2917]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 09:13:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:14 volumio volumio[2739]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:13:14 volumio volumio[2739]: assert.ok(self.idling) Feb 17 09:13:14 volumio volumio[2739]: error: The expression evaluated to a falsy value: Feb 17 09:13:14 volumio volumio[2739]: assert.ok(self.idling) Feb 17 09:13:14 volumio volumio[2739]: info: MPD running with PID2964 Feb 17 09:13:14 volumio volumio[2739]: ,establishing connection Feb 17 09:13:14 volumio volumio[2739]: error: updateQueue error: null Feb 17 09:13:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:14 volumio go-librespot[3055]: go-librespot daemon starting... Feb 17 09:13:14 volumio go-librespot[3056]: time="2026-02-17T09:13:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:14 volumio go-librespot[3056]: time="2026-02-17T09:13:14+07:00" level=debug msg="app state loaded" Feb 17 09:13:14 volumio volumio[2739]: info: Completed starting Core Plugins Feb 17 09:13:14 volumio volumio[2739]: info: ------------------------------------------- Feb 17 09:13:14 volumio volumio[2739]: info: ----- MyVolumio plugins startup ---- Feb 17 09:13:14 volumio volumio[2739]: info: ------------------------------------------- Feb 17 09:13:14 volumio go-librespot[3056]: time="2026-02-17T09:13:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:14 volumio volumio[2739]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:13:14 volumio volumio[2739]: error: updateQueue error: null Feb 17 09:13:15 volumio go-librespot[3056]: time="2026-02-17T09:13:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:15 volumio go-librespot[3056]: time="2026-02-17T09:13:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:15 volumio go-librespot[3056]: time="2026-02-17T09:13:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:15 volumio go-librespot[3056]: time="2026-02-17T09:13:15+07:00" level=info msg="zeroconf server listening on port 36825" Feb 17 09:13:15 volumio go-librespot[3056]: time="2026-02-17T09:13:15+07:00" level=debug msg="obtained new client token: AAB5YYlF+y4xwL2CY9LwKKXaz9AMD2TMKRyjU/LmreXXiIra8m4WrJeLEQFuu0XT6g71ck2YjPqgKMsIVyuW/5t0Va+dH+Myu7bncKJrMYBh/oCMwut1NxQbUZaVtIWNtdt9v950GJC2UeQDe9IvMVqYog2jW7fetZddIY07RP0aaCVBDZsuSwzfIedpLrWxjLJuvQMyOZGyDiKbn+SVh/y0+oyfK6Jabn38a64WSyJjUAN3klp07Fu06A==" Feb 17 09:13:15 volumio go-librespot[3056]: time="2026-02-17T09:13:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:16 volumio go-librespot[3056]: time="2026-02-17T09:13:16+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:16 volumio go-librespot[3056]: time="2026-02-17T09:13:16+07:00" level=debug msg="completed challenge" Feb 17 09:13:16 volumio go-librespot[3056]: time="2026-02-17T09:13:16+07: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 17 09:13:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:16 volumio volumio[2739]: info: Initializing connection to go-librespot Websocket Feb 17 09:13:16 volumio volumio[2739]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:13:19 volumio volumio[2739]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:13:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 17 09:13:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:19 volumio go-librespot[3066]: go-librespot daemon starting... Feb 17 09:13:19 volumio go-librespot[3067]: time="2026-02-17T09:13:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:19 volumio go-librespot[3067]: time="2026-02-17T09:13:19+07:00" level=debug msg="app state loaded" Feb 17 09:13:19 volumio go-librespot[3067]: time="2026-02-17T09:13:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:19 volumio volumio[2739]: info: Initializing connection to go-librespot Websocket Feb 17 09:13:19 volumio go-librespot[3067]: time="2026-02-17T09:13:19+07:00" level=debug msg="new websocket client" Feb 17 09:13:19 volumio volumio[2739]: info: Connection to go-librespot Websocket established Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=info msg="zeroconf server listening on port 40917" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="obtained new client token: AABviI+aSPU5ZuiO/OFqfvroiSebbFnzmDbKNRf5unOhVGF3PG6a8CmfON0ZCN8hyD9FBqGkMLcPx75yJJ/99Wa0aUGXPpI90keEpdipK1Q3DIQpTaXVe97GlN9CFj7noQ6rLveL3cPKcKJpLJYHR+2aFOBvQxw7gyzarcncFZrnlzrB5HQVlBFk5bKuv7hcD+ic/ySnpY8VWoyC/ekGyZt1DQF1ye6pB7jjuqa73J/DjPGQiNRscz/TTw==" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07:00" level=debug msg="completed challenge" Feb 17 09:13:20 volumio go-librespot[3067]: time="2026-02-17T09:13:20+07: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 17 09:13:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:20 volumio volumio[2739]: info: Connection to go-librespot Websocket closed Feb 17 09:13:22 volumio volumio[2739]: info: Getting Spotify volume Feb 17 09:13:23 volumio volumio[2739]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:13:23 volumio volumio[2739]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:13:23 volumio volumio[2739]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:13:23 volumio volumio[2739]: errno: -111, Feb 17 09:13:23 volumio volumio[2739]: code: 'ECONNREFUSED', Feb 17 09:13:23 volumio volumio[2739]: syscall: 'connect', Feb 17 09:13:23 volumio volumio[2739]: address: '127.0.0.1', Feb 17 09:13:23 volumio volumio[2739]: port: 9879, Feb 17 09:13:23 volumio volumio[2739]: response: undefined Feb 17 09:13:23 volumio volumio[2739]: } Feb 17 09:13:23 volumio volumio[2739]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:13:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 17 09:13:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:23 volumio go-librespot[3100]: go-librespot daemon starting... Feb 17 09:13:23 volumio go-librespot[3101]: time="2026-02-17T09:13:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:23 volumio go-librespot[3101]: time="2026-02-17T09:13:23+07:00" level=debug msg="app state loaded" Feb 17 09:13:23 volumio go-librespot[3101]: time="2026-02-17T09:13:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=info msg="zeroconf server listening on port 33439" Feb 17 09:13:24 volumio sudo[3110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:12' Feb 17 09:13:24 volumio sudo[3110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="obtained new client token: AADsyUls2688EF+FB86RyNakDzXLofvOkKyyvV/wwQQiDHpoRRlx0ItOZndlG1tzq1pDzi4WHbESuFJN5PKaYJd0/o+TtjCyoifIfaUuufpbNmQZZsHxNlP43YZRVtW8ac0gTaHmcchCTDO8R9Vei5A00/leAL07NaFeRLQC7m16Ck0iOU/z2Vjoa60PX4cXttcL9vO7iJpAl3PP5tBvMDYbLYfl0qI3pl3TJxS+DZa6vYuN/3kdBP+opA==" Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:24 volumio sudo[3110]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07:00" level=debug msg="completed challenge" Feb 17 09:13:24 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:13:24 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:13:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:24 volumio go-librespot[3101]: time="2026-02-17T09:13:24+07: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 17 09:13:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:13:24 volumio systemd[1]: volumio.service: Consumed 49.351s CPU time. Feb 17 09:13:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:13:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20167. Feb 17 09:13:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:13:25 volumio systemd[1]: volumio.service: Consumed 49.351s CPU time. Feb 17 09:13:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:13:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:13:25 volumio nmbd[966]: [2026/02/17 09:13:25.222959, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 17 09:13:25 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 17 09:13:25 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 17 09:13:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 17 09:13:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:28 volumio go-librespot[3140]: go-librespot daemon starting... Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=debug msg="app state loaded" Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:28 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:28 volumio volumio[3126]: info: ----- Volumio3 ---- Feb 17 09:13:28 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:28 volumio volumio[3126]: info: ----- System startup ---- Feb 17 09:13:28 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:28 volumio go-librespot[3141]: time="2026-02-17T09:13:28+07:00" level=info msg="zeroconf server listening on port 45725" Feb 17 09:13:29 volumio go-librespot[3141]: time="2026-02-17T09:13:29+07:00" level=debug msg="obtained new client token: AACbzf/tcC2ZD/YwAU0CaEDj6z+DwJF02ZnVGS91tbahs0a91P4FOCY1aLpwTKxf/59B9mTHN/dTqwSnywojOLQEKuD+/T5aI+ekFGe3XywGK2WGhrI8EiPCnI28x/XALlPDGRhyCQhQD2HaTsGN9bf3hnyFSdCmp94fBNWMkjpTPCR0wCbU99zHSCOFZrp1hjMzhZB+HWQN2yxY6xYXHzUH14zCjjqFiyg30OzlHotje6siRJh47dE=" Feb 17 09:13:29 volumio go-librespot[3141]: time="2026-02-17T09:13:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:29 volumio go-librespot[3141]: time="2026-02-17T09:13:29+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:29 volumio go-librespot[3141]: time="2026-02-17T09:13:29+07:00" level=debug msg="completed challenge" Feb 17 09:13:29 volumio go-librespot[3141]: time="2026-02-17T09:13:29+07: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 17 09:13:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:29 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:29] [connect] Successful connection Feb 17 09:13:30 volumio volumio[3126]: info: MYVOLUMIO Environment detected Feb 17 09:13:30 volumio volumio[3126]: info: Plugin folders cleanup Feb 17 09:13:30 volumio volumio[3126]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category audio_interface Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category miscellanea Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category music_service Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category plugins.json Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category system_controller Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category user_interface Feb 17 09:13:30 volumio volumio[3126]: info: Scanning into folder /data/plugins/ Feb 17 09:13:30 volumio volumio[3126]: info: Scanning category music_service Feb 17 09:13:30 volumio volumio[3126]: info: Plugin folders cleanup completed Feb 17 09:13:30 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:30 volumio volumio[3126]: info: ----- Core plugins startup ---- Feb 17 09:13:30 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:30 volumio volumio[3126]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:13:30 volumio volumio[3126]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:13:30 volumio volumio[3126]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:13:30 volumio volumio[3126]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:13:30 volumio volumio[3126]: info: Loading plugins from folder /data/plugins/ Feb 17 09:13:30 volumio volumio[3126]: info: Loading plugin "system"... Feb 17 09:13:30 volumio volumio[3126]: info: Loading plugin "appearance"... Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "network"... Feb 17 09:13:32 volumio volumio[3126]: info: Refreshing Cached IP Addresses Feb 17 09:13:32 volumio sudo[3161]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:13:32 volumio sudo[3161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:32 volumio sudo[3163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:13:32 volumio sudo[3161]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:32 volumio sudo[3163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "services"... Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "alsa_controller"... Feb 17 09:13:32 volumio sudo[3163]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:32 volumio sudo[3170]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:13:32 volumio sudo[3170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:32 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "wizard"... Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "networkfs"... Feb 17 09:13:32 volumio volumio[3126]: info: Starting Udev Watcher for removable devices Feb 17 09:13:32 volumio volumio[3126]: info: Ignoring mount for partition: boot Feb 17 09:13:32 volumio volumio[3126]: info: Ignoring mount for partition: volumio Feb 17 09:13:32 volumio volumio[3126]: info: Ignoring mount for partition: volumio_data Feb 17 09:13:32 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "upnp"... Feb 17 09:13:32 volumio volumio[3126]: info: [1771294412696] Starting Upmpd Daemon Feb 17 09:13:32 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "my_music"... Feb 17 09:13:32 volumio volumio[3126]: info: Loading plugin "mpd"... Feb 17 09:13:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 17 09:13:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:32 volumio go-librespot[3194]: go-librespot daemon starting... Feb 17 09:13:32 volumio go-librespot[3195]: time="2026-02-17T09:13:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:32 volumio go-librespot[3195]: time="2026-02-17T09:13:32+07:00" level=debug msg="app state loaded" Feb 17 09:13:32 volumio go-librespot[3195]: time="2026-02-17T09:13:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:33 volumio volumio[3126]: info: Loading plugin "upnp_browser"... Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=info msg="zeroconf server listening on port 41205" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="obtained new client token: AAAiX5Qz74VneuqLMDmiVGGQyyFmTQup6UlwJrbS+1QyTSn03K1p6oms/QlFn+U4d+fHyNc9ZChJ1LfN4q8yVo5onGT+AQOcUmlQBvtC0XYr/8ynH5Fb+EDhXNH3JPxFFdE5atpZXQNSXV5Yo0nGABlbTxJTih6jVhXNsbgBAHxrQR7KpWPO9tSPvb2yJqWDvhfj68QPTy9hVDpxkfrB+7HsnBeTJKx4iNNrctgvDcHfuJqXL4S5d/n1iA==" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07:00" level=debug msg="completed challenge" Feb 17 09:13:33 volumio go-librespot[3195]: time="2026-02-17T09:13:33+07: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 17 09:13:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:35 volumio sudo[3170]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:36 volumio volumio[3126]: info: Starting UPNP Browser Feb 17 09:13:36 volumio volumio[3126]: info: Loading plugin "alarm-clock"... Feb 17 09:13:36 volumio volumio[3126]: info: Loading plugin "airplay_emulation"... Feb 17 09:13:36 volumio volumio[3126]: info: Starting Shairport Sync Feb 17 09:13:36 volumio volumio[3126]: info: Loading plugin "last_100"... Feb 17 09:13:36 volumio volumio[3126]: info: Loading plugin "webradio"... Feb 17 09:13:36 volumio volumio[3126]: info: Loading plugin "i2s_dacs"... Feb 17 09:13:36 volumio volumio[3126]: info: Loading plugin "volumiodiscovery"... Feb 17 09:13:36 volumio volumio[3126]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:13:36 volumio volumio[3126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:13:36 volumio volumio[3126]: *** WARNING *** For more information see Feb 17 09:13:36 volumio volumio[3126]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:13:36 volumio volumio[3126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:13:36 volumio volumio[3126]: *** WARNING *** For more information see Feb 17 09:13:36 volumio node[3126]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:13:36 volumio node[3126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:13:36 volumio node[3126]: *** WARNING *** For more information see Feb 17 09:13:36 volumio node[3126]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:13:36 volumio node[3126]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:13:36 volumio node[3126]: *** WARNING *** For more information see Feb 17 09:13:36 volumio volumio[3126]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:13:36 volumio volumio[3126]: info: Discovery: Started advertising with name: Volumio Feb 17 09:13:37 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:13:37 volumio volumio[3126]: info: Loading plugin "spop"... Feb 17 09:13:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 17 09:13:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:37 volumio go-librespot[3204]: go-librespot daemon starting... Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=debug msg="app state loaded" Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:37 volumio go-librespot[3205]: time="2026-02-17T09:13:37+07:00" level=info msg="zeroconf server listening on port 37505" Feb 17 09:13:38 volumio go-librespot[3205]: time="2026-02-17T09:13:38+07:00" level=debug msg="obtained new client token: AAB75CCZX/PzahhAKl/ZqotJFpdKVdvx+zNID7h+uqy6DCU39vaGvvGpBTjNTgysfYfQkOk/J5gbianj3FvRW+L7bvem9LTWAWOJf8u4yuPpBgQ6ffs1SsBFGQ+s7KBcyeEBKof+gd8iYJRovLJRSobFOMiRpuR3Xj26Qyk8nq2HaNDC4wHDjL3x7mb/PX1E122ZPuJVzJ24+T2HgZBzoeo9rio4RE33EC3yXxN/f3ptf0kjPjiGchkK+g==" Feb 17 09:13:38 volumio go-librespot[3205]: time="2026-02-17T09:13:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:38 volumio go-librespot[3205]: time="2026-02-17T09:13:38+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:38 volumio go-librespot[3205]: time="2026-02-17T09:13:38+07:00" level=debug msg="completed challenge" Feb 17 09:13:38 volumio go-librespot[3205]: time="2026-02-17T09:13:38+07: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 17 09:13:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:38 volumio volumio[3126]: info: Loading plugin "ytcr"... Feb 17 09:13:41 volumio volumio[3126]: info: Loading plugin "ytmusic"... Feb 17 09:13:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 17 09:13:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:41 volumio go-librespot[3212]: go-librespot daemon starting... Feb 17 09:13:41 volumio go-librespot[3213]: time="2026-02-17T09:13:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:41 volumio go-librespot[3213]: time="2026-02-17T09:13:41+07:00" level=debug msg="app state loaded" Feb 17 09:13:41 volumio go-librespot[3213]: time="2026-02-17T09:13:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=info msg="zeroconf server listening on port 36029" Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="obtained new client token: AAC9FU+JaAjcGazO9Dv8hqn7hycEHgnUL2us1WYlHmmNKHVwasKSr32E4deKGmhAqc6l2lInGOkOvaXHym2Q76Lij7arrHEsDpLZYtQM9s2/whmTwIBmanrNQ/LayX8YIF0BIKowoQP+5+4UzgkApitXoIsQXgzNhErOphJrBOur/namZRhg9On0W8FHEejvOaIc7snh0J3bFBzR4XDLCnZ6qNbPqrV/XQkghwWWXEgx2mHPWENS8Jc9tw==" Feb 17 09:13:42 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:42] [connect] Successful connection Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:42 volumio volumio[3126]: info: Loading plugin "outputs"... Feb 17 09:13:42 volumio volumio[3126]: info: Loading plugin "albumart"... Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07:00" level=debug msg="completed challenge" Feb 17 09:13:42 volumio volumio[3126]: info: Plugin example_plugin is not enabled Feb 17 09:13:42 volumio volumio[3126]: info: Loading plugin "inputs"... Feb 17 09:13:42 volumio volumio[3126]: info: Loading plugin "updater_comm"... Feb 17 09:13:42 volumio go-librespot[3213]: time="2026-02-17T09:13:42+07: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 17 09:13:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:42 volumio volumio[3126]: info: Plugin mpdemulation is not enabled Feb 17 09:13:42 volumio volumio[3126]: info: Loading plugin "rest_api"... Feb 17 09:13:42 volumio volumio[3126]: info: Loading plugin "websocket"... Feb 17 09:13:43 volumio volumio[3126]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:13:43 volumio volumio[3126]: info: Loading plugin "RoonBridge"... Feb 17 09:13:43 volumio volumio[3126]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 09:13:43 volumio volumio[3126]: info: Loading i18n strings for locale en Feb 17 09:13:43 volumio volumio[3126]: Updating browse sources language Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:43 volumio volumio[3235]: Forking 3 albumart workers Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::initPlayerControls Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:13:43 volumio volumio[3126]: Express server listening on port 3000 Feb 17 09:13:43 volumio volumio[3126]: [Metrics] WebUI: 16s 146.01ms Feb 17 09:13:43 volumio volumio[3126]: info: CoreStateMachine::resetVolumioState Feb 17 09:13:43 volumio volumio[3126]: info: CoreStateMachine::getcurrentVolume Feb 17 09:13:43 volumio volumio[3126]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:13:44 volumio sudo[3279]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:13:44 volumio sudo[3279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:44 volumio sudo[3282]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:13:44 volumio sudo[3282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:44 volumio sudo[3279]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:44 volumio volumio[3126]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:13:44 volumio sudo[3282]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:44 volumio volumio[3126]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:13:44 volumio volumio[3126]: info: CoreStateMachine::pushState Feb 17 09:13:44 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:44 volumio volumio[3126]: info: CoreStateMachine::updateTrackBlock Feb 17 09:13:44 volumio volumio[3126]: info: CorePlayQueue::getTrackBlock Feb 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:13:44 volumio volumio-remote-updater[25144]: [2026-02-17 09:13:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771294422 101 Feb 17 09:13:44 volumio volumio[3126]: 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 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:44 volumio volumio[3126]: info: Reloading queue from file Feb 17 09:13:44 volumio volumio[3126]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:13:44 volumio volumio[3126]: info: CoreStateMachine::pushState Feb 17 09:13:44 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:44 volumio volumio[3126]: info: CoreStateMachine::setRandom null Feb 17 09:13:44 volumio volumio[3126]: info: CoreStateMachine::pushState Feb 17 09:13:44 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:44 volumio volumio[3126]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:44 volumio volumio[3126]: info: Setting Device type: Raspberry PI Feb 17 09:13:44 volumio volumio[3126]: info: Completed loading Core Plugins Feb 17 09:13:44 volumio volumio[3126]: info: Preparing to generate the ALSA configuration file Feb 17 09:13:45 volumio volumio[3126]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:13:45 volumio volumio[3126]: info: CoreStateMachine::pushState Feb 17 09:13:45 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:45 volumio volumio[3126]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:13:45 volumio volumio[3126]: info: Output device has changed, restarting MPD Feb 17 09:13:45 volumio sudo[3297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:13:45 volumio sudo[3297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:45 volumio volumio[3126]: info: Output device has changed, restarting Shairport Sync Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:45 volumio sudo[3299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:13:45 volumio sudo[3299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:45 volumio sudo[3299]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:45 volumio sudo[3302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:13:45 volumio sudo[3302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:45 volumio volumio[3126]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:13:45 volumio volumio[3126]: info: ___________ START PLUGINS ___________ Feb 17 09:13:45 volumio sudo[3297]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:45 volumio volumio[3126]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:13:45 volumio volumio[3126]: info: Creating MPD Configuration file Feb 17 09:13:45 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:45 volumio volumio[3126]: info: [1771294425446] CoreMusicLibrary::Adding element Media Servers Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:45 volumio sudo[3312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:13:45 volumio sudo[3312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:45 volumio volumio[3126]: info: UPNP Browser: Client initialized successfully Feb 17 09:13:45 volumio sudo[3310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:13:45 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:13:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:13:45 volumio systemd[1]: mpd.service: Consumed 7.126s CPU time. Feb 17 09:13:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:13:45 volumio sudo[3310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:13:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:13:45 volumio sudo[3310]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:13:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:13:45 volumio volumio[3126]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:45 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:13:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:13:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 17 09:13:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:13:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:13:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:13:45 volumio volumio[3126]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:45 volumio volumio[3126]: info: [1771294425819] CoreMusicLibrary::Adding element Last_100 Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:45 volumio volumio[3126]: info: [1771294425838] CoreMusicLibrary::Adding element Webradio Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:45 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:13:45 volumio volumio[3126]: info: Initializing BBC Radios Feb 17 09:13:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:13:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:45 volumio go-librespot[3328]: go-librespot daemon starting... Feb 17 09:13:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=debug msg="app state loaded" Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:46 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:13:46 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:46 volumio volumio[3126]: info: Creating Spotify config file Feb 17 09:13:46 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:46 volumio sudo[3331]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:13:46 volumio sudo[3331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:13:46 volumio sudo[3331]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:46 volumio volumio[3245]: Starting albumart workers Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:13:46 volumio go-librespot[3330]: time="2026-02-17T09:13:46+07:00" level=info msg="zeroconf server listening on port 44223" Feb 17 09:13:47 volumio go-librespot[3330]: time="2026-02-17T09:13:47+07:00" level=debug msg="obtained new client token: AAAZBzHcp3biysNetwIUFSlQCvicraYysR0tM/NMmnNEDYCXN06T6SoZln8RshCTmErkr73IfTrZdZtz77gGfj0K5kyEdTOwUK9/G4odqFauMgIOueGYw4DJ9kWzd5mYcf3oZrtICQqbHz3IjSIQvP1vSpKT8ciD1fnU1Z+M83gkkZUgmsD2APawABXl/UfNzqTowXawTUAkWT2p2ZbVRtAlYzLyOlLvaqxiy2Hd89IBZSYNQCUonK4=" Feb 17 09:13:47 volumio volumio[3247]: Starting albumart workers Feb 17 09:13:47 volumio go-librespot[3330]: time="2026-02-17T09:13:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:47 volumio volumio[3246]: Starting albumart workers Feb 17 09:13:47 volumio go-librespot[3330]: time="2026-02-17T09:13:47+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:47 volumio go-librespot[3330]: time="2026-02-17T09:13:47+07:00" level=debug msg="completed challenge" Feb 17 09:13:47 volumio go-librespot[3330]: time="2026-02-17T09:13:47+07: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 17 09:13:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:47 volumio volumio[3126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:47 volumio volumio[3126]: info: [1771294427569] CoreMusicLibrary::Adding element YouTube Music Feb 17 09:13:47 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:47 volumio volumio[3126]: Cannot find translation for source YouTube Music Feb 17 09:13:47 volumio volumio[3126]: info: Volumio Calling Home Feb 17 09:13:47 volumio sudo[3352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 09:13:47 volumio sudo[3352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:47 volumio sudo[3352]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:48 volumio volumio[3126]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:13:48 volumio volumio[3126]: info: Discovery: Found device Volumio Feb 17 09:13:48 volumio volumio[3126]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:48 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:48 volumio volumio[3126]: info: MPD Permissions set Feb 17 09:13:48 volumio volumio[3126]: info: MPD Permissions set Feb 17 09:13:48 volumio volumio[3126]: info: Upmpdcli Daemon Started Feb 17 09:13:48 volumio volumio[3126]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:13:48 volumio volumio[3126]: info: Discovery: Found device Volumio Feb 17 09:13:48 volumio volumio[3126]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:48 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:48 volumio volumio[3126]: info: Volumio called home Feb 17 09:13:48 volumio volumio[3126]: info: Spotify config file written Feb 17 09:13:48 volumio sudo[3364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:13:48 volumio sudo[3364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:49 volumio go-librespot[3372]: go-librespot daemon starting... Feb 17 09:13:49 volumio sudo[3364]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=debug msg="app state loaded" Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:49 volumio volumio[3126]: 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 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:13:49 volumio volumio[3126]: info: No need to fix Spotify hosts Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:49 volumio go-librespot[3373]: time="2026-02-17T09:13:49+07:00" level=info msg="zeroconf server listening on port 39971" Feb 17 09:13:50 volumio volumio[3126]: info: Starting Shairport Sync Feb 17 09:13:50 volumio volumio[3126]: info: Starting Shairport Sync Feb 17 09:13:50 volumio volumio[3126]: info: Starting Shairport Sync Feb 17 09:13:50 volumio go-librespot[3373]: time="2026-02-17T09:13:50+07:00" level=debug msg="obtained new client token: AACdNjHDVzdcYojW8tLrT31xPT/SqAXrBqk/lkHELIKHF2w3nyUKJ3dC4U/WQ3IzKTdqjJIWbTrqP31XtASo+peCinAFW6yAPSZ7NaErBGnkHRJZozxK/TF9th9uF5GflCSivTzaBnRbYv6FZU7fHenmA4hnXci9BIkKGjaWopf7twscvOBEzn15aTARNbRXLxSu71HNgAGOE0HMqWyUcx5HcpL8HI77isjLExIrgrZGEQl2KiDd/mw=" Feb 17 09:13:50 volumio sudo[3398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:13:50 volumio sudo[3398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:50 volumio sudo[3401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:13:50 volumio sudo[3401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:50 volumio sudo[3402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:13:50 volumio sudo[3402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:13:50 volumio go-librespot[3373]: time="2026-02-17T09:13:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:13:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:13:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:13:50 volumio systemd[1]: shairport-sync.service: Consumed 2.215s CPU time. Feb 17 09:13:50 volumio go-librespot[3373]: time="2026-02-17T09:13:50+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:50 volumio go-librespot[3373]: time="2026-02-17T09:13:50+07:00" level=debug msg="completed challenge" Feb 17 09:13:50 volumio go-librespot[3373]: time="2026-02-17T09:13:50+07: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 17 09:13:50 volumio volumio[3126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:13:50 volumio volumio[3126]: SPOTIFY: BQDmfbt8lQ0obThqTB1s0LdNVhJEY1Dl59q-WibxJAfU3ToBPmFVZpZ-6j4PNbedzn9pr6oM3jhKvQyUW3WErTi8DdE3Jmj2vpMUs-rrtosBqTkNcMiU-CUgNpaWSmwt-Cl3WbIQQQOD9Ic3_wff7-SgI8WoL8MwsHYtORmw8nLpwmRv1MN1q_geAGyVhYMUROZV108kGSEr0u7oG8HeyvWd5JhzIpAFJicyNvclDMBScwb93WNHMABI_8KmJmsVDLVmGMJeq6AsFWr_zWhbp_TRiuPu_-178zuuRVccNUhOT0lOrsexO7En Feb 17 09:13:50 volumio volumio[3126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:13:50 volumio volumio[3126]: info: New Spotify access token = BQDmfbt8lQ0obThqTB1s0LdNVhJEY1Dl59q-WibxJAfU3ToBPmFVZpZ-6j4PNbedzn9pr6oM3jhKvQyUW3WErTi8DdE3Jmj2vpMUs-rrtosBqTkNcMiU-CUgNpaWSmwt-Cl3WbIQQQOD9Ic3_wff7-SgI8WoL8MwsHYtORmw8nLpwmRv1MN1q_geAGyVhYMUROZV108kGSEr0u7oG8HeyvWd5JhzIpAFJicyNvclDMBScwb93WNHMABI_8KmJmsVDLVmGMJeq6AsFWr_zWhbp_TRiuPu_-178zuuRVccNUhOT0lOrsexO7En Feb 17 09:13:50 volumio volumio[3126]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:13:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:13:50 volumio sudo[3398]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:50 volumio volumio[3126]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:50 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:50 volumio volumio[3126]: info: Shairport-Sync Started Feb 17 09:13:50 volumio volumio[3126]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:13:50 volumio sudo[3401]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:13:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:13:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:13:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:13:50 volumio volumio[3126]: info: Shairport-Sync Started Feb 17 09:13:50 volumio sudo[3402]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:50 volumio volumio[3126]: info: Shairport-Sync Started Feb 17 09:13:51 volumio volumio[3126]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 09:13:51 volumio volumio[3126]: info: Spotify Successfully logged in Feb 17 09:13:51 volumio volumio[3126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:13:51 volumio volumio[3126]: info: [1771294431112] CoreMusicLibrary::Adding element Spotify Feb 17 09:13:51 volumio volumio[3126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:13:51 volumio volumio[3126]: Cannot find translation for source YouTube Music Feb 17 09:13:51 volumio volumio[3126]: Cannot find translation for source Spotify Feb 17 09:13:51 volumio volumio[3126]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 09:13:51 volumio volumio[3126]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:13:51 volumio volumio[3126]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:13:51 volumio volumio[3126]: info: CoreCommandRouter::volumioGetState Feb 17 09:13:51 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:51 volumio volumio[3126]: info: CoreStateMachine::pushState Feb 17 09:13:51 volumio volumio[3126]: info: CorePlayQueue::getTrack 0 Feb 17 09:13:51 volumio volumio[3126]: info: CoreCommandRouter::volumioPushState Feb 17 09:13:53 volumio volumio[3126]: info: go-librespot daemon successfully initialized Feb 17 09:13:53 volumio mpd[3349]: 2026-02-17T09:13:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:13:53 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:13:53 volumio sudo[3302]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:53 volumio sudo[3312]: pam_unix(sudo:session): session closed for user root Feb 17 09:13:53 volumio volumio[3126]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:13:53 volumio volumio[3126]: assert.ok(self.idling) Feb 17 09:13:53 volumio volumio[3126]: error: The expression evaluated to a falsy value: Feb 17 09:13:53 volumio volumio[3126]: assert.ok(self.idling) Feb 17 09:13:53 volumio volumio[3126]: info: MPD running with PID3349 Feb 17 09:13:53 volumio volumio[3126]: ,establishing connection Feb 17 09:13:53 volumio volumio[3126]: error: updateQueue error: null Feb 17 09:13:53 volumio volumio[3126]: info: Completed starting Core Plugins Feb 17 09:13:53 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:53 volumio volumio[3126]: info: ----- MyVolumio plugins startup ---- Feb 17 09:13:53 volumio volumio[3126]: info: ------------------------------------------- Feb 17 09:13:53 volumio volumio[3126]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:13:53 volumio volumio[3126]: error: updateQueue error: null Feb 17 09:13:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 17 09:13:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:53 volumio go-librespot[3443]: go-librespot daemon starting... Feb 17 09:13:53 volumio go-librespot[3444]: time="2026-02-17T09:13:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:53 volumio go-librespot[3444]: time="2026-02-17T09:13:53+07:00" level=debug msg="app state loaded" Feb 17 09:13:53 volumio go-librespot[3444]: time="2026-02-17T09:13:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=info msg="zeroconf server listening on port 45543" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="obtained new client token: AAC9LEaTxiby74gG51hK+Z5jrrikLvZxq8WVyec1rDN27WZ28SBuhDx4ODPhFRxkV85wGPTbOTidcrBY3vJF6cCF/ZB/N3tMpQVqKhnbTB0jctroEiW8ipeURunRqcx8FJV9hRzMMZCctiIPFkBQxjVS4+STD68cOMrEve8v3DSJU5A+ID/un6FWQECtvZlW01GTZaS7ds+3sH2Evd+6N/rKT3KbKfGG/GWKAvCL36vURa1tBpTZa+ppsg==" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07:00" level=debug msg="completed challenge" Feb 17 09:13:54 volumio go-librespot[3444]: time="2026-02-17T09:13:54+07: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 17 09:13:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:56 volumio volumio[3126]: info: Initializing connection to go-librespot Websocket Feb 17 09:13:56 volumio volumio[3126]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:13:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 17 09:13:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:13:58 volumio go-librespot[3453]: go-librespot daemon starting... Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=debug msg="app state loaded" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:13:58 volumio volumio[3126]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=info msg="zeroconf server listening on port 32803" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=debug msg="obtained new client token: AACP3ZvLItOygBtPbuDlAdJvkuLA3ZTcGsD+pk8pIkfW95fZju9vtJplBZwvkJIFCyUHuSYcyf8anRw0zVrciGr3K2G12iaVuFJ0rAv1vnFnXAd3anVo+Mky1ezx8wBhlCdv9Z1B3lJ298l4glLxoYk3jQfNUupq7xUuMsB+P60SJIEdzHSl4wXjYZms523SMBZHEgSWMQDAfGFq/0krNHTcPGH1DaYVS/ol2Ohk/XOsyvlmGmVvdIE8QA==" Feb 17 09:13:58 volumio go-librespot[3454]: time="2026-02-17T09:13:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:13:59 volumio volumio[3126]: info: Initializing connection to go-librespot Websocket Feb 17 09:13:59 volumio go-librespot[3454]: time="2026-02-17T09:13:59+07:00" level=debug msg="new websocket client" Feb 17 09:13:59 volumio volumio[3126]: info: Connection to go-librespot Websocket established Feb 17 09:13:59 volumio go-librespot[3454]: time="2026-02-17T09:13:59+07:00" level=debug msg="completed keyexchange" Feb 17 09:13:59 volumio go-librespot[3454]: time="2026-02-17T09:13:59+07:00" level=debug msg="completed challenge" Feb 17 09:13:59 volumio go-librespot[3454]: time="2026-02-17T09:13:59+07: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 17 09:13:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:13:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:13:59 volumio volumio[3126]: info: Connection to go-librespot Websocket closed Feb 17 09:14:02 volumio volumio[3126]: info: Getting Spotify volume Feb 17 09:14:02 volumio volumio[3126]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:02 volumio volumio[3126]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:14:02 volumio volumio[3126]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 09:14:02 volumio volumio[3126]: errno: -111, Feb 17 09:14:02 volumio volumio[3126]: code: 'ECONNREFUSED', Feb 17 09:14:02 volumio volumio[3126]: syscall: 'connect', Feb 17 09:14:02 volumio volumio[3126]: address: '127.0.0.1', Feb 17 09:14:02 volumio volumio[3126]: port: 9879, Feb 17 09:14:02 volumio volumio[3126]: response: undefined Feb 17 09:14:02 volumio volumio[3126]: } Feb 17 09:14:02 volumio volumio[3126]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 17 09:14:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:02 volumio go-librespot[3472]: go-librespot daemon starting... Feb 17 09:14:02 volumio go-librespot[3474]: time="2026-02-17T09:14:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:02 volumio go-librespot[3474]: time="2026-02-17T09:14:02+07:00" level=debug msg="app state loaded" Feb 17 09:14:02 volumio go-librespot[3474]: time="2026-02-17T09:14:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=info msg="zeroconf server listening on port 37421" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="obtained new client token: AAD+uzR/00jZRt4k/SdGXC6fmwbhC/4m0Ra6zDKPEOkSdBebxml1OZas5iPo5VVWKJLc+RBFFzkoZfM6IzfPVVdYyzhV4l8NNaF8TfG+PzQ3zv+jarbZEZYxs2wNDLLpZSPio4OZlOb8A8Tt0l5H8lCQAzdxrviajm4VybT+oSO5YgcFD9HxYavvvc/ZKfTRKa7E/2TpzWsBots0P/CYbutuYmSzSGYxjUwgioA2EmkHzQLVjqHardE=" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07:00" level=debug msg="completed challenge" Feb 17 09:14:03 volumio go-librespot[3474]: time="2026-02-17T09:14:03+07: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 17 09:14:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:03 volumio sudo[3497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:13' Feb 17 09:14:03 volumio sudo[3497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:03 volumio sudo[3497]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:04 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 09:14:04 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 09:14:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 09:14:04 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 17 09:14:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:14:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:14:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20168. Feb 17 09:14:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 09:14:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 09:14:04 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 17 09:14:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 09:14:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 09:14:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 17 09:14:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:06 volumio go-librespot[3524]: go-librespot daemon starting... Feb 17 09:14:06 volumio go-librespot[3525]: time="2026-02-17T09:14:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:06 volumio go-librespot[3525]: time="2026-02-17T09:14:06+07:00" level=debug msg="app state loaded" Feb 17 09:14:06 volumio go-librespot[3525]: time="2026-02-17T09:14:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=info msg="zeroconf server listening on port 42741" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="obtained new client token: AADRBwr6LFWxT9p6aFyMG4O3cvI2dOPW9igErS9QsRSK50PyGZQRpbrcwkoL1hALpcDfTl7hyIIPfw8Y85L+HeHtIGhd/0EEn1LU+OTYri70MwslS0DK58wi4hNTA4oJeuoy8HVdBQql5mMLYS0mYJg9BIdF+8u16NNTA3rfnBvjNGlOeW352kNuVx57xogGGATOgmDo2PK12Po6bMYzoqvGuH6UXsPGkSvv6Nt2v0iGHctrWAvOjskGOQ==" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:07 volumio go-librespot[3525]: time="2026-02-17T09:14:07+07:00" level=debug msg="completed challenge" Feb 17 09:14:07 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:08 volumio volumio[3509]: info: ----- Volumio3 ---- Feb 17 09:14:08 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:08 volumio volumio[3509]: info: ----- System startup ---- Feb 17 09:14:08 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:08 volumio go-librespot[3525]: time="2026-02-17T09:14:08+07: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 17 09:14:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:09 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:09] [connect] Successful connection Feb 17 09:14:09 volumio volumio[3509]: info: MYVOLUMIO Environment detected Feb 17 09:14:09 volumio volumio[3509]: info: Plugin folders cleanup Feb 17 09:14:09 volumio volumio[3509]: info: Scanning into folder /volumio/app/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category audio_interface Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category miscellanea Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category music_service Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category plugins.json Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category system_controller Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category user_interface Feb 17 09:14:09 volumio volumio[3509]: info: Scanning into folder /data/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Scanning category music_service Feb 17 09:14:09 volumio volumio[3509]: info: Plugin folders cleanup completed Feb 17 09:14:09 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:09 volumio volumio[3509]: info: ----- Core plugins startup ---- Feb 17 09:14:09 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Adding plugin upnp to MyMusic Plugins Feb 17 09:14:09 volumio volumio[3509]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 09:14:09 volumio volumio[3509]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugins from folder /data/plugins/ Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugin "system"... Feb 17 09:14:09 volumio volumio[3509]: info: Loading plugin "appearance"... Feb 17 09:14:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 17 09:14:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:11 volumio go-librespot[3545]: go-librespot daemon starting... Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="app state loaded" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "network"... Feb 17 09:14:11 volumio volumio[3509]: info: Refreshing Cached IP Addresses Feb 17 09:14:11 volumio sudo[3555]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:14:11 volumio sudo[3555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:11 volumio sudo[3555]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:11 volumio sudo[3557]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:14:11 volumio sudo[3557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "services"... Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "alsa_controller"... Feb 17 09:14:11 volumio sudo[3557]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:11 volumio sudo[3565]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 09:14:11 volumio sudo[3565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=info msg="zeroconf server listening on port 37517" Feb 17 09:14:11 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "wizard"... Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "networkfs"... Feb 17 09:14:11 volumio volumio[3509]: info: Starting Udev Watcher for removable devices Feb 17 09:14:11 volumio volumio[3509]: info: Ignoring mount for partition: boot Feb 17 09:14:11 volumio volumio[3509]: info: Ignoring mount for partition: volumio Feb 17 09:14:11 volumio volumio[3509]: info: Ignoring mount for partition: volumio_data Feb 17 09:14:11 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "volumio_command_line_client"... Feb 17 09:14:11 volumio go-librespot[3546]: time="2026-02-17T09:14:11+07:00" level=debug msg="obtained new client token: AAABXbLPiiX/CJkfqLqNvmXS5pH+b5GjkyFvF4TXWmHH05yBhZDxLGxH15hJo25O0gK7KdU7ysDxKrzso901N00e9+K9fB5eoh5rJYpuipGR9MEdL8E0bGocyrMHHcbnc3a6z68pMh+T0NNf/E5WYFytFEdVY6EaK9h+yBzKvYsetjSGUn0WBYi85mTaEQlZ+QYO39BfMEgQ3AGPeqwwvICEQ1dJ6Q4UU+AexATUSGSI6jmtH62eX0nk+A==" Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "upnp"... Feb 17 09:14:11 volumio volumio[3509]: info: [1771294451933] Starting Upmpd Daemon Feb 17 09:14:11 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "my_music"... Feb 17 09:14:11 volumio volumio[3509]: info: Loading plugin "mpd"... Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 09:14:12 volumio volumio[3509]: info: Loading plugin "upnp_browser"... Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07:00" level=debug msg="completed challenge" Feb 17 09:14:12 volumio go-librespot[3546]: time="2026-02-17T09:14:12+07: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 17 09:14:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:14 volumio sudo[3565]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:15 volumio volumio[3509]: info: Starting UPNP Browser Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "alarm-clock"... Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "airplay_emulation"... Feb 17 09:14:15 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "last_100"... Feb 17 09:14:15 volumio volumio[3509]: info: Loading plugin "webradio"... Feb 17 09:14:16 volumio volumio[3509]: info: Loading plugin "i2s_dacs"... Feb 17 09:14:16 volumio volumio[3509]: info: Loading plugin "volumiodiscovery"... Feb 17 09:14:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 17 09:14:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio volumio[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio node[3509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio node[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio node[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio node[3509]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 09:14:16 volumio node[3509]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 09:14:16 volumio node[3509]: *** WARNING *** For more information see Feb 17 09:14:16 volumio volumio[3509]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 09:14:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:16 volumio go-librespot[3589]: go-librespot daemon starting... Feb 17 09:14:16 volumio volumio[3509]: info: Discovery: Started advertising with name: Volumio Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="app state loaded" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:16 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 09:14:16 volumio volumio[3509]: info: Loading plugin "spop"... Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=info msg="zeroconf server listening on port 35719" Feb 17 09:14:16 volumio go-librespot[3590]: time="2026-02-17T09:14:16+07:00" level=debug msg="obtained new client token: AABwjoE8qlACABLY+n9D7LK/bb/AySsdp+VjFr/JHl+VfwKzT8bQaotjIyfa5wAW0b84H5ALluqJFoTIAuz/ZzT+CYRfiq3OUT0JmifBOcCWPtZFLvxIHg0FXwTwt7zXIg3OBtlGSdW2cKt8/vyjBw/Dh54VgRDcx78UsVVTvOp0Gnilzw0hQct3ZsoiK6dXYmm5R96WXqb1AgXYNwtjEE04P2P2zHgYdZFfHwtI4sYUpP1JNpaVEbRe+A==" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07:00" level=debug msg="completed challenge" Feb 17 09:14:17 volumio go-librespot[3590]: time="2026-02-17T09:14:17+07: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 17 09:14:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:18 volumio volumio[3509]: info: Loading plugin "ytcr"... Feb 17 09:14:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 17 09:14:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:20 volumio go-librespot[3599]: go-librespot daemon starting... Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="app state loaded" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:20 volumio volumio[3509]: info: Loading plugin "ytmusic"... Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:20 volumio go-librespot[3600]: time="2026-02-17T09:14:20+07:00" level=info msg="zeroconf server listening on port 38865" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="obtained new client token: AABRcF1XxU/USxEelAc23TF/cc47L3L3l+SMGcI3nH/5ZQjwNnM/931C+4dZPDKhN5pJM0iKVuPsC1ukAWdqO2XkhjcxaYolHYPKpU/p13XCibj3OIB8KF8vgQVTsv4njKiIUR/3jH6799nSIw9Tfh1YAAPyJUtJtljyRFLjkP19YM+B3yPTUM545cYzCO0mziu9RHadsH2p2jELB5UGZX3pCWkmyAYlAynyt+1npJcwCrhHmPcvHp4=" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07:00" level=debug msg="completed challenge" Feb 17 09:14:21 volumio go-librespot[3600]: time="2026-02-17T09:14:21+07: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 17 09:14:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:21 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:21] [connect] Successful connection Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "outputs"... Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "albumart"... Feb 17 09:14:21 volumio volumio[3509]: info: Plugin example_plugin is not enabled Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "inputs"... Feb 17 09:14:21 volumio volumio[3509]: info: Loading plugin "updater_comm"... Feb 17 09:14:22 volumio volumio[3509]: info: Plugin mpdemulation is not enabled Feb 17 09:14:22 volumio volumio[3509]: info: Loading plugin "rest_api"... Feb 17 09:14:22 volumio volumio[3509]: info: Loading plugin "websocket"... Feb 17 09:14:22 volumio volumio[3509]: info: Starting Socket.io Server version 1.7.4 Feb 17 09:14:22 volumio volumio[3509]: info: Loading plugin "RoonBridge"... Feb 17 09:14:22 volumio volumio[3509]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 09:14:22 volumio volumio[3509]: info: Loading i18n strings for locale en Feb 17 09:14:22 volumio volumio[3509]: Updating browse sources language Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::initPlayerControls Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3621]: Forking 3 albumart workers Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:14:22 volumio volumio[3509]: Express server listening on port 3000 Feb 17 09:14:22 volumio volumio[3509]: [Metrics] WebUI: 15s 953.99ms Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::resetVolumioState Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::getcurrentVolume Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:14:23 volumio sudo[3663]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 09:14:23 volumio sudo[3663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:23 volumio sudo[3663]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:23 volumio sudo[3665]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 09:14:23 volumio sudo[3665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:23 volumio sudo[3665]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:23 volumio volumio[3509]: info: Volumio Network Manager: Network status updated: 1 Feb 17 09:14:23 volumio volumio[3509]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::updateTrackBlock Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrackBlock Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:14:23 volumio volumio-remote-updater[25144]: [2026-02-17 09:14:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771294461 101 Feb 17 09:14:23 volumio volumio[3509]: 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 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:23 volumio volumio[3509]: info: Reloading queue from file Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::setRepeat null single undefined Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::setRandom null Feb 17 09:14:23 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:23 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:23 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:23 volumio volumio[3509]: info: Setting Device type: Raspberry PI Feb 17 09:14:24 volumio volumio[3509]: info: Completed loading Core Plugins Feb 17 09:14:24 volumio volumio[3509]: info: Preparing to generate the ALSA configuration file Feb 17 09:14:24 volumio volumio[3509]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:14:24 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:24 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:24 volumio volumio[3509]: info: Asound.conf file unchanged, so no further update is needed Feb 17 09:14:24 volumio volumio[3509]: info: Output device has changed, restarting MPD Feb 17 09:14:24 volumio volumio[3509]: info: Output device has changed, restarting Shairport Sync Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:24 volumio sudo[3682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 09:14:24 volumio sudo[3682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio sudo[3684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:14:24 volumio sudo[3687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:14:24 volumio sudo[3684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio volumio[3509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:14:24 volumio sudo[3687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio volumio[3509]: info: ___________ START PLUGINS ___________ Feb 17 09:14:24 volumio volumio[3509]: info: ControllerMpd::onStart: Initializing MPD Feb 17 09:14:24 volumio volumio[3509]: info: Creating MPD Configuration file Feb 17 09:14:24 volumio sudo[3684]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:24 volumio sudo[3682]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:24 volumio volumio[3509]: info: [1771294464460] CoreMusicLibrary::Adding element Media Servers Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:24 volumio volumio[3509]: info: UPNP Browser: Client initialized successfully Feb 17 09:14:24 volumio sudo[3695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 09:14:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 17 09:14:24 volumio sudo[3695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:24 volumio sudo[3695]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:24 volumio sudo[3697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 09:14:24 volumio sudo[3697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:24 volumio go-librespot[3699]: go-librespot daemon starting... Feb 17 09:14:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 09:14:24 volumio go-librespot[3703]: time="2026-02-17T09:14:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:24 volumio go-librespot[3703]: time="2026-02-17T09:14:24+07:00" level=debug msg="app state loaded" Feb 17 09:14:24 volumio go-librespot[3703]: time="2026-02-17T09:14:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:14:24 volumio volumio[3509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:14:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:14:24 volumio systemd[1]: mpd.service: Consumed 7.047s CPU time. Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:14:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:14:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:14:24 volumio volumio[3509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:24 volumio volumio[3509]: info: [1771294464825] CoreMusicLibrary::Adding element Last_100 Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:24 volumio volumio[3509]: info: [1771294464840] CoreMusicLibrary::Adding element Webradio Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:14:24 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:14:24 volumio volumio[3509]: info: Initializing BBC Radios Feb 17 09:14:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 09:14:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 09:14:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 09:14:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 09:14:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 09:14:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 09:14:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 09:14:25 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 09:14:25 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:25 volumio volumio[3509]: info: Creating Spotify config file Feb 17 09:14:25 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=info msg="zeroconf server listening on port 43335" Feb 17 09:14:25 volumio sudo[3728]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 09:14:25 volumio sudo[3728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 09:14:25 volumio sudo[3728]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="obtained new client token: AADkuZ6QRM71S7CqaLaoEVhGbm1jnXwoANfw5asA263TjTbu7asdijLq6wrcE2DSrKUHgc0ozquMmYF0Huiad143qoW6r5Al8I2V1P3fV8pLHHAQx/k5TMx3CXx9mh57mPNm7rzQhbp/cACKII3soaueMpHVp5EuM7lmJ704CMTURKXuUVQxJe0koqw1rfbDDxqIuNoa6X/1upDJ61cdVKcnPaiSTGjloz+nLOjOgROu4WD2BAPVHgb1Tw==" Feb 17 09:14:25 volumio go-librespot[3703]: time="2026-02-17T09:14:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:26 volumio go-librespot[3703]: time="2026-02-17T09:14:26+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:26 volumio go-librespot[3703]: time="2026-02-17T09:14:26+07:00" level=debug msg="completed challenge" Feb 17 09:14:26 volumio go-librespot[3703]: time="2026-02-17T09:14:26+07: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 17 09:14:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:26 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:26 volumio volumio[3509]: info: [1771294466267] CoreMusicLibrary::Adding element YouTube Music Feb 17 09:14:26 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:26 volumio volumio[3509]: Cannot find translation for source YouTube Music Feb 17 09:14:26 volumio volumio[3509]: info: Volumio Calling Home Feb 17 09:14:26 volumio sudo[3738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 09:14:26 volumio sudo[3738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:26 volumio sudo[3738]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:26 volumio volumio[3631]: Starting albumart workers Feb 17 09:14:26 volumio volumio[3632]: Starting albumart workers Feb 17 09:14:26 volumio volumio[3634]: Starting albumart workers Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: Found device Volumio Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:27 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 09:14:27 volumio volumio[3509]: info: Discovery: Found device Volumio Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:27 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:27 volumio volumio[3509]: info: MPD Permissions set Feb 17 09:14:27 volumio volumio[3509]: info: MPD Permissions set Feb 17 09:14:27 volumio volumio[3509]: info: Upmpdcli Daemon Started Feb 17 09:14:27 volumio volumio[3509]: info: Spotify config file written Feb 17 09:14:27 volumio volumio[3509]: 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 17 09:14:27 volumio sudo[3746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 09:14:27 volumio sudo[3746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 09:14:27 volumio volumio[3509]: info: No need to fix Spotify hosts Feb 17 09:14:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:27 volumio go-librespot[3758]: go-librespot daemon starting... Feb 17 09:14:27 volumio sudo[3746]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:27 volumio go-librespot[3759]: time="2026-02-17T09:14:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:27 volumio go-librespot[3759]: time="2026-02-17T09:14:27+07:00" level=debug msg="app state loaded" Feb 17 09:14:27 volumio go-librespot[3759]: time="2026-02-17T09:14:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=info msg="zeroconf server listening on port 44669" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="obtained new client token: AACcaiI4CjWKjU0bllGG+AmTYCb5/cR9FRiWqsXLEqVSA/gzcame0n4UbzeCxkTUPQvqvqp4QhyTVr9Yo9zlZ8hQ2Y3MiEN9FEiiphqckFC1EKoB94wIIPQlACg4PjvsKi4jsgjUPbDjn0/bKGp8ZnTtKevw2/hfbNW0tIwlttPE4QU46JeDdQVjqBR641ZsvynbWRvfaO0FyWJb1qv2ux+971JsIsiqzmkiLqoP8zQYRVBHCF45xjSIKA==" Feb 17 09:14:28 volumio go-librespot[3759]: time="2026-02-17T09:14:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:29 volumio go-librespot[3759]: time="2026-02-17T09:14:29+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:29 volumio go-librespot[3759]: time="2026-02-17T09:14:29+07:00" level=debug msg="completed challenge" Feb 17 09:14:29 volumio go-librespot[3759]: time="2026-02-17T09:14:29+07: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 17 09:14:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:29 volumio volumio[3509]: info: Volumio called home Feb 17 09:14:29 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:29 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:29 volumio volumio[3509]: info: Starting Shairport Sync Feb 17 09:14:29 volumio sudo[3787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:14:29 volumio sudo[3787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:29 volumio sudo[3789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:14:29 volumio sudo[3789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:29 volumio sudo[3792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 09:14:29 volumio sudo[3792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:14:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:14:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio systemd[1]: shairport-sync.service: Consumed 2.272s CPU time. Feb 17 09:14:29 volumio volumio[3509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:14:29 volumio volumio[3509]: SPOTIFY: BQBz-mGbDXypweTAHOPwkd444Gp8E1UAahNAEvBDcOatvnOi9rNIHK8Vmncrw0u5nD7JyirHjqwyAVvJEVQpfpxw0AiBOwxms2GEKx1bNKBYHNIrUyUEIIGzDg_qGnvGKco3-cT42B9ISjGT7vQVbSzihxZjW72J5IrBm4E3ygFwOIKm71JY0Zsf-p2TUfjQpzS7LWRppmo1n-GMPBrK3Z7ws7rk2yf8l_M--ejvE8bKqO5YAMHKLIJXm9-N4Qjv3b8MiIUZEsTOAI-bMz0Xkf-du0zz6QLZBTBH3MDz6bdWr9IdZWqfJsS1 Feb 17 09:14:29 volumio volumio[3509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 09:14:29 volumio volumio[3509]: info: New Spotify access token = BQBz-mGbDXypweTAHOPwkd444Gp8E1UAahNAEvBDcOatvnOi9rNIHK8Vmncrw0u5nD7JyirHjqwyAVvJEVQpfpxw0AiBOwxms2GEKx1bNKBYHNIrUyUEIIGzDg_qGnvGKco3-cT42B9ISjGT7vQVbSzihxZjW72J5IrBm4E3ygFwOIKm71JY0Zsf-p2TUfjQpzS7LWRppmo1n-GMPBrK3Z7ws7rk2yf8l_M--ejvE8bKqO5YAMHKLIJXm9-N4Qjv3b8MiIUZEsTOAI-bMz0Xkf-du0zz6QLZBTBH3MDz6bdWr9IdZWqfJsS1 Feb 17 09:14:29 volumio volumio[3509]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 09:14:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:29 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:29 volumio sudo[3787]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 09:14:29 volumio volumio[3509]: info: Shairport-Sync Started Feb 17 09:14:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 09:14:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio volumio[3509]: Error adding Membership: Error: addMembership EINVAL Feb 17 09:14:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 09:14:29 volumio sudo[3792]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:29 volumio sudo[3789]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:29 volumio volumio[3509]: info: Shairport-Sync Started Feb 17 09:14:30 volumio volumio[3509]: info: Shairport-Sync Started Feb 17 09:14:30 volumio volumio[3509]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 09:14:30 volumio volumio[3509]: info: Spotify Successfully logged in Feb 17 09:14:30 volumio volumio[3509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 09:14:30 volumio volumio[3509]: info: [1771294470084] CoreMusicLibrary::Adding element Spotify Feb 17 09:14:30 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 09:14:30 volumio volumio[3509]: Cannot find translation for source YouTube Music Feb 17 09:14:30 volumio volumio[3509]: Cannot find translation for source Spotify Feb 17 09:14:30 volumio volumio[3509]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 09:14:30 volumio volumio[3509]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 09:14:31 volumio volumio[3509]: info: VolumeController:: Volume=100 Mute =false Feb 17 09:14:31 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:31 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:31 volumio volumio[3509]: info: CoreStateMachine::pushState Feb 17 09:14:31 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:31 volumio volumio[3509]: info: CoreCommandRouter::volumioPushState Feb 17 09:14:32 volumio volumio[3509]: info: go-librespot daemon successfully initialized Feb 17 09:14:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 17 09:14:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:32 volumio go-librespot[3836]: go-librespot daemon starting... Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="app state loaded" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:32 volumio mpd[3735]: 2026-02-17T09:14:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 09:14:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 09:14:32 volumio sudo[3697]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:32 volumio sudo[3687]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:32 volumio volumio[3509]: error: MPD error: The expression evaluated to a falsy value: Feb 17 09:14:32 volumio volumio[3509]: assert.ok(self.idling) Feb 17 09:14:32 volumio volumio[3509]: error: The expression evaluated to a falsy value: Feb 17 09:14:32 volumio volumio[3509]: assert.ok(self.idling) Feb 17 09:14:32 volumio volumio[3509]: info: MPD running with PID3735 Feb 17 09:14:32 volumio volumio[3509]: ,establishing connection Feb 17 09:14:32 volumio volumio[3509]: error: updateQueue error: null Feb 17 09:14:32 volumio volumio[3509]: info: Completed starting Core Plugins Feb 17 09:14:32 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:32 volumio volumio[3509]: info: ----- MyVolumio plugins startup ---- Feb 17 09:14:32 volumio volumio[3509]: info: ------------------------------------------- Feb 17 09:14:32 volumio volumio[3509]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 09:14:32 volumio volumio[3509]: error: updateQueue error: null Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 09:14:32 volumio go-librespot[3837]: time="2026-02-17T09:14:32+07:00" level=info msg="zeroconf server listening on port 46625" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="obtained new client token: AAAs80VfG5kwGM/47VOTrt6+BObFiWHRhgTaj60lvL5KIETqRHP8EihHrh+yDX//Adgwz3hKpld4+1x8iWFAoF/c8C+foamKVy8HoIEeLc+eWrpZmdtk1nSe3CozmD83ZjPyEKT4yrlq98hBK5onK7lCleQ9+dSkoKauNn28/K5MHhl6q5K97jHZJzDQNfKwS/o/wDJpeo+w6XAQn3eqT6OnLNAhY3FpCBwqKyqam4ho++UP60jz5ZM=" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07:00" level=debug msg="completed challenge" Feb 17 09:14:33 volumio go-librespot[3837]: time="2026-02-17T09:14:33+07: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 17 09:14:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:35 volumio volumio[3509]: info: Initializing connection to go-librespot Websocket Feb 17 09:14:35 volumio volumio[3509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:14:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 17 09:14:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:36 volumio go-librespot[3849]: go-librespot daemon starting... Feb 17 09:14:36 volumio go-librespot[3850]: time="2026-02-17T09:14:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:36 volumio go-librespot[3850]: time="2026-02-17T09:14:36+07:00" level=debug msg="app state loaded" Feb 17 09:14:36 volumio go-librespot[3850]: time="2026-02-17T09:14:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=info msg="zeroconf server listening on port 46483" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="obtained new client token: AABAHiT6qVpB0fhX7XRdpzQnV2WgBXyYh1/NIU9LG8XqliAF2FonSdZYPl86kjg1Su2ye/cFTGHz3RUBaySvSN4qk1RmtZcSQV7dOLIz3r9XR9JZ9GNl+4YYntIIp0bK5cDvqpWQIk/C5IIE+7z8lHhlZZx+1YMwk7vb/mjj/hdwoUxf7fwGXtxuWxuVd25BrrI4P0ucp7apRt3JJw1bc2NuieDv0/8wdc8JqeQb1Vs+0Rb6L7ge3nKlGw==" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07:00" level=debug msg="completed challenge" Feb 17 09:14:37 volumio volumio[3509]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 09:14:37 volumio go-librespot[3850]: time="2026-02-17T09:14:37+07: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 17 09:14:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:38 volumio volumio[3509]: info: Initializing connection to go-librespot Websocket Feb 17 09:14:38 volumio volumio[3509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 09:14:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 17 09:14:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:40 volumio go-librespot[3857]: go-librespot daemon starting... Feb 17 09:14:40 volumio go-librespot[3858]: time="2026-02-17T09:14:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:40 volumio go-librespot[3858]: time="2026-02-17T09:14:40+07:00" level=debug msg="app state loaded" Feb 17 09:14:40 volumio go-librespot[3858]: time="2026-02-17T09:14:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:41 volumio volumio[3509]: info: Initializing connection to go-librespot Websocket Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="new websocket client" Feb 17 09:14:41 volumio volumio[3509]: info: Connection to go-librespot Websocket established Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=info msg="zeroconf server listening on port 41949" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="obtained new client token: AAAdXdqLs2FWWGjZWBANmGxySExNqDGpaITV53GkbYhZyidr/gfrYZop6kLl/zkm62br+xHy+8m/ZkdbZsxodSC3slMr/93DCNjqka7lLfcg/jaeuJQ50vzmoSI2MDbA2sajnXm7eFH+tB2+VJxf0yCJHwrVgl6W8FK+s4xWzkQCRTT4BAEKlEhqnnmxxXR3Agni0DfRZkfT7WE0Y1Y7gwBu978DkZvLLbDmtLJlKlH1gealrmTtj2KHHA==" Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07:00" level=debug msg="completed challenge" Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 09:14:41 volumio volumio[3509]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 09:14:41 volumio go-librespot[3858]: time="2026-02-17T09:14:41+07: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 17 09:14:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 09:14:43 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:43 volumio volumio[3509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 09:14:43 volumio volumio[3509]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 09:14:43 volumio volumio[3509]: info: MyVolumio login type: Token Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 09:14:43 volumio volumio[3509]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 09:14:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 17 09:14:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 09:14:45 volumio go-librespot[3879]: go-librespot daemon starting... Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="app state loaded" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 09:14:45 volumio volumio[3509]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 09:14:45 volumio volumio[3509]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 09:14:45 volumio volumio[3509]: info: Streaming services startup Feb 17 09:14:45 volumio volumio[3509]: info: Starting Streaming Daemon Feb 17 09:14:45 volumio sudo[3888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 09:14:45 volumio sudo[3888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 09:14:45 volumio volumio[3509]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 09:14:45 volumio sudo[3888]: pam_unix(sudo:session): session closed for user root Feb 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=info msg="zeroconf server listening on port 38373" Feb 17 09:14:45 volumio volumio[3509]: info: Getting Spotify volume Feb 17 09:14:45 volumio volumio[3509]: info: Connection to go-librespot Websocket closed Feb 17 09:14:45 volumio volumio[3509]: error: Cannot start Volumio Streaming Daemon Feb 17 09:14:45 volumio volumio[3509]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 09:14:45 volumio volumio[3509]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 09:14:45 volumio volumio[3509]: 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 17 09:14:45 volumio go-librespot[3880]: time="2026-02-17T09:14:45+07:00" level=debug msg="obtained new client token: AACc1s3HU3izotBzHVCqauAyyruTDafFcDSjYhdDLjRpc7m6lJK3HvG6wLwAdcbEY49jqNZ7ClU4Vo60NHzzZB1ThDQvbSSl5vj9bCRM94iJV4sA85llDHtnEGWlHZ1/x9S8J6A3a05NH7PlizQt71al86CESugG9tRAtodKXwvSR1Lb+5wJCWkw70b0tEp5pPGWkFeGlHCTCK6TtcZWLlYyC4ydi3aItnuePnmCbWpOSBv0pTVbCnNO/A==" Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 09:14:46 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:46 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:46 volumio volumio[3509]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 09:14:46 volumio volumio[3509]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 09:14:46 volumio volumio[3509]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 09:14:46 volumio volumio[3509]: info: Aligning Spotify Volume to Volumio Volume Feb 17 09:14:46 volumio volumio[3509]: info: CoreCommandRouter::volumioGetState Feb 17 09:14:46 volumio volumio[3509]: info: CorePlayQueue::getTrack 0 Feb 17 09:14:46 volumio volumio[3509]: info: Setting Spotify Volume from Volumio: 100 Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=debug msg="completed keyexchange" Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07:00" level=debug msg="completed challenge" Feb 17 09:14:46 volumio go-librespot[3880]: time="2026-02-17T09:14:46+07: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 17 09:14:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 09:14:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 09:14:46 volumio volumio[3509]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:46 volumio volumio[3509]: Error: socket hang up Feb 17 09:14:46 volumio volumio[3509]: at connResetException (node:internal/errors:720:14) Feb 17 09:14:46 volumio volumio[3509]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 09:14:46 volumio volumio[3509]: at Socket.emit (node:events:526:35) Feb 17 09:14:46 volumio volumio[3509]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 09:14:46 volumio volumio[3509]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 09:14:46 volumio volumio[3509]: code: 'ECONNRESET', Feb 17 09:14:46 volumio volumio[3509]: response: undefined Feb 17 09:14:46 volumio volumio[3509]: } Feb 17 09:14:46 volumio volumio[3509]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 09:14:47 volumio sudo[3908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 09:13' Feb 17 09:14:47 volumio sudo[3908]: 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"