Feb 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+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 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+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 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+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 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+07:00" level=info msg="zeroconf server listening on port 43667" Feb 18 20:30:00 volumio volumio[15505]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 20:30:00 volumio volumio[15505]: info: Loading i18n strings for locale en Feb 18 20:30:00 volumio volumio[15505]: Updating browse sources language Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+07:00" level=debug msg="obtained new client token: AAAMNj031YHHGJ5wIZOkLdwm9hXUGBIUhgv77KWI8BWdGyU39AJZKN3WCG9B6Flu3yEi8gP9zshR/2KDxXJOCuk9mc8C5WethhqeZ6/CL7zRzhY/rfJ467tz4YktePNWonjZDmUfity5A4i+KtllN0677nkpNCvqNV9RRRqt2ooNzPqS7NEUGjMjC14I3ack1XKp3vwPuNvsxdUzqxG2ZsLI9KafSsE4yHofBGHAR7CkQ30gDMeA0SalRQ==" Feb 18 20:30:00 volumio volumio[15616]: Forking 3 albumart workers Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::initPlayerControls Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:30:00 volumio volumio[15505]: Express server listening on port 3000 Feb 18 20:30:00 volumio volumio[15505]: [Metrics] WebUI: 16s 212.44ms Feb 18 20:30:00 volumio volumio[15505]: info: CoreStateMachine::resetVolumioState Feb 18 20:30:00 volumio volumio[15505]: info: CoreStateMachine::getcurrentVolume Feb 18 20:30:00 volumio volumio[15505]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+07:00" level=debug msg="completed challenge" Feb 18 20:30:00 volumio go-librespot[15626]: time="2026-02-18T20:30:00+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 18 20:30:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:01 volumio sudo[15670]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:30:01 volumio sudo[15670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:01 volumio sudo[15670]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:01 volumio sudo[15672]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:30:01 volumio sudo[15672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:01 volumio sudo[15672]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:01 volumio volumio[15505]: info: Volumio Network Manager: Network status updated: 1 Feb 18 20:30:01 volumio volumio[15505]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::pushState Feb 18 20:30:01 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::updateTrackBlock Feb 18 20:30:01 volumio volumio[15505]: info: CorePlayQueue::getTrackBlock Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:30:01 volumio volumio-remote-updater[25144]: [2026-02-18 20:30:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771421399 101 Feb 18 20:30:01 volumio volumio[15505]: 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 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:01 volumio volumio[15505]: info: Reloading queue from file Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::setRepeat null single undefined Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::pushState Feb 18 20:30:01 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::setRandom null Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::pushState Feb 18 20:30:01 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:01 volumio volumio[15505]: info: Setting Device type: Raspberry PI Feb 18 20:30:01 volumio volumio[15505]: info: Completed loading Core Plugins Feb 18 20:30:01 volumio volumio[15505]: info: Preparing to generate the ALSA configuration file Feb 18 20:30:01 volumio volumio[15505]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:30:01 volumio volumio[15505]: info: CoreStateMachine::pushState Feb 18 20:30:01 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:01 volumio volumio[15505]: info: Asound.conf file unchanged, so no further update is needed Feb 18 20:30:01 volumio volumio[15505]: info: Output device has changed, restarting MPD Feb 18 20:30:01 volumio volumio[15505]: info: Output device has changed, restarting Shairport Sync Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:01 volumio sudo[15688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 20:30:01 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:01 volumio sudo[15688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:02 volumio sudo[15690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:30:02 volumio sudo[15690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:02 volumio sudo[15690]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:02 volumio sudo[15692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:30:02 volumio sudo[15692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:02 volumio volumio[15505]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:30:02 volumio volumio[15505]: info: ___________ START PLUGINS ___________ Feb 18 20:30:02 volumio sudo[15688]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:02 volumio volumio[15505]: info: ControllerMpd::onStart: Initializing MPD Feb 18 20:30:02 volumio volumio[15505]: info: Creating MPD Configuration file Feb 18 20:30:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:02 volumio volumio[15505]: info: [1771421402225] CoreMusicLibrary::Adding element Media Servers Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:02 volumio sudo[15702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:30:02 volumio sudo[15702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:02 volumio volumio[15505]: info: UPNP Browser: Client initialized successfully Feb 18 20:30:02 volumio sudo[15702]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:30:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:30:02 volumio systemd[1]: mpd.service: Consumed 7.154s CPU time. Feb 18 20:30:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:30:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:30:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:30:02 volumio sudo[15704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:30:02 volumio sudo[15704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:30:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:30:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:30:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:30:02 volumio volumio[15505]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:30:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:30:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:30:02 volumio volumio[15505]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:30:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:02 volumio volumio[15505]: info: [1771421402639] CoreMusicLibrary::Adding element Last_100 Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:02 volumio volumio[15505]: info: [1771421402663] CoreMusicLibrary::Adding element Webradio Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:30:02 volumio volumio[15505]: info: Initializing BBC Radios Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:02 volumio volumio[15505]: info: Creating Spotify config file Feb 18 20:30:02 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:03 volumio sudo[15718]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 20:30:03 volumio sudo[15718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 20:30:03 volumio sudo[15718]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:03 volumio volumio[15640]: Starting albumart workers Feb 18 20:30:04 volumio volumio[15638]: Starting albumart workers Feb 18 20:30:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 20:30:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:04 volumio volumio[15505]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:04 volumio volumio[15505]: info: [1771421404131] CoreMusicLibrary::Adding element YouTube Music Feb 18 20:30:04 volumio go-librespot[15734]: go-librespot daemon starting... Feb 18 20:30:04 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:04 volumio volumio[15505]: Cannot find translation for source YouTube Music Feb 18 20:30:04 volumio volumio[15505]: info: Volumio Calling Home Feb 18 20:30:04 volumio go-librespot[15735]: time="2026-02-18T20:30:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:04 volumio sudo[15742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 20:30:04 volumio sudo[15742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:04 volumio sudo[15742]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:04 volumio volumio[15639]: Starting albumart workers Feb 18 20:30:04 volumio go-librespot[15735]: time="2026-02-18T20:30:04+07:00" level=info msg="zeroconf server listening on port 37593" Feb 18 20:30:05 volumio volumio[15505]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:30:05 volumio volumio[15505]: info: Discovery: Found device Volumio Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:05 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:05 volumio volumio[15505]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:30:05 volumio volumio[15505]: info: Discovery: Found device Volumio Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:05 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:05 volumio volumio[15505]: info: MPD Permissions set Feb 18 20:30:05 volumio volumio[15505]: info: MPD Permissions set Feb 18 20:30:05 volumio volumio[15505]: info: Upmpdcli Daemon Started Feb 18 20:30:05 volumio volumio[15505]: info: Spotify config file written Feb 18 20:30:05 volumio sudo[15749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:30:05 volumio sudo[15749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:05 volumio volumio[15505]: 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 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio systemd[1]: go-librespot-daemon.service: Killing process 15738 (go-librespot) with signal SIGKILL. Feb 18 20:30:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:30:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:05 volumio go-librespot[15762]: go-librespot daemon starting... Feb 18 20:30:05 volumio sudo[15749]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:05 volumio go-librespot[15768]: time="2026-02-18T20:30:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:05 volumio go-librespot[15768]: time="2026-02-18T20:30:05+07:00" level=debug msg="app state loaded" Feb 18 20:30:05 volumio go-librespot[15768]: time="2026-02-18T20:30:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:05 volumio volumio[15505]: info: No need to fix Spotify hosts Feb 18 20:30:06 volumio go-librespot[15768]: time="2026-02-18T20:30:06+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 18 20:30:06 volumio go-librespot[15768]: time="2026-02-18T20:30:06+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 18 20:30:06 volumio go-librespot[15768]: time="2026-02-18T20:30:06+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 18 20:30:06 volumio volumio[15505]: info: Volumio called home Feb 18 20:30:06 volumio go-librespot[15768]: time="2026-02-18T20:30:06+07:00" level=info msg="zeroconf server listening on port 43315" Feb 18 20:30:06 volumio go-librespot[15768]: time="2026-02-18T20:30:06+07:00" level=debug msg="obtained new client token: AADVBt3BOQu4HpLonFr787joxArWNpdMxhulG27+O8AuK4ixIuosQVToZF/tHgTrC1MOfAP8NeO9qEbThNds+3RmyRzVn+elzjLHLwVloPkBfqNxHGakalPz3YeuA3tqBP8k3JV2T04EbkotlRKLBO7Cf7NIY4TM2OtfgT2UQLvBedhsebWzQnZvQznwIwc+xQnMRHdh+FP3w+n7UvIS7lXw97R7q+Th/NKx/i75mZPo0dBoofmDVgnJNw==" Feb 18 20:30:06 volumio volumio[15505]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:30:06 volumio volumio[15505]: SPOTIFY: BQAfMlADkmoggI-qdakN8VjVBIa-ZAAU04_0NqC0Hfa4ZHnoK_6edvbe-n5VXv3y_-bIII0oT_AgNt9H-Igbv-tm3hvZj2LCOA6vxO-Cj0vVesr_tArTLPpj5PkbBWByLlEcJzf1FkR-73mnxb_00xSAHUhmc5MlU4CVC0cV7ZOQpJx9x3ShTEguUQTEI5uBxbC1H1k9ZFUu-X6pQVQTVF8pkL9npqwI4FgwTz-tb7fYAcBA8yUl7TvzCJhgVP7xreYD_CwLKrK3zljc4pY4v94-88VxanWlQ_JhzQqZiqGrDmUdaiAO_Yys Feb 18 20:30:06 volumio volumio[15505]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:30:06 volumio volumio[15505]: info: New Spotify access token = BQAfMlADkmoggI-qdakN8VjVBIa-ZAAU04_0NqC0Hfa4ZHnoK_6edvbe-n5VXv3y_-bIII0oT_AgNt9H-Igbv-tm3hvZj2LCOA6vxO-Cj0vVesr_tArTLPpj5PkbBWByLlEcJzf1FkR-73mnxb_00xSAHUhmc5MlU4CVC0cV7ZOQpJx9x3ShTEguUQTEI5uBxbC1H1k9ZFUu-X6pQVQTVF8pkL9npqwI4FgwTz-tb7fYAcBA8yUl7TvzCJhgVP7xreYD_CwLKrK3zljc4pY4v94-88VxanWlQ_JhzQqZiqGrDmUdaiAO_Yys Feb 18 20:30:06 volumio volumio[15505]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:30:06 volumio volumio[15505]: info: Starting Shairport Sync Feb 18 20:30:06 volumio volumio[15505]: info: Starting Shairport Sync Feb 18 20:30:06 volumio volumio[15505]: info: Starting Shairport Sync Feb 18 20:30:06 volumio go-librespot[15768]: time="2026-02-18T20:30:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:07 volumio sudo[15788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:30:07 volumio sudo[15788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:07 volumio sudo[15790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:30:07 volumio sudo[15790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:07 volumio go-librespot[15768]: time="2026-02-18T20:30:07+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:07 volumio go-librespot[15768]: time="2026-02-18T20:30:07+07:00" level=debug msg="completed challenge" Feb 18 20:30:07 volumio sudo[15792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:30:07 volumio sudo[15792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:07 volumio go-librespot[15768]: time="2026-02-18T20:30: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 18 20:30:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:30:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:30:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:30:07 volumio systemd[1]: shairport-sync.service: Consumed 2.339s CPU time. Feb 18 20:30:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:30:07 volumio sudo[15792]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:07 volumio sudo[15790]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:07 volumio sudo[15788]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:07 volumio volumio[15505]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:07 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:07 volumio volumio[15505]: info: Shairport-Sync Started Feb 18 20:30:07 volumio volumio[15505]: Error adding Membership: Error: addMembership EINVAL Feb 18 20:30:07 volumio volumio[15505]: info: Shairport-Sync Started Feb 18 20:30:07 volumio volumio[15505]: info: Shairport-Sync Started Feb 18 20:30:07 volumio volumio[15505]: 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 18 20:30:07 volumio volumio[15505]: info: Spotify Successfully logged in Feb 18 20:30:07 volumio volumio[15505]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:07 volumio volumio[15505]: info: [1771421407664] CoreMusicLibrary::Adding element Spotify Feb 18 20:30:07 volumio volumio[15505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:07 volumio volumio[15505]: Cannot find translation for source YouTube Music Feb 18 20:30:07 volumio volumio[15505]: Cannot find translation for source Spotify Feb 18 20:30:08 volumio volumio[15505]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 20:30:08 volumio volumio[15505]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:30:09 volumio volumio[15505]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:30:09 volumio volumio[15505]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:09 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:09 volumio volumio[15505]: info: CoreStateMachine::pushState Feb 18 20:30:09 volumio volumio[15505]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:09 volumio volumio[15505]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:09 volumio volumio[15505]: info: go-librespot daemon successfully initialized Feb 18 20:30:10 volumio mpd[15733]: 2026-02-18T20:30:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 20:30:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 20:30:10 volumio sudo[15704]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:10 volumio sudo[15692]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 20:30:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:10 volumio volumio[15505]: error: MPD error: The expression evaluated to a falsy value: Feb 18 20:30:10 volumio volumio[15505]: assert.ok(self.idling) Feb 18 20:30:10 volumio volumio[15505]: error: The expression evaluated to a falsy value: Feb 18 20:30:10 volumio volumio[15505]: assert.ok(self.idling) Feb 18 20:30:10 volumio volumio[15505]: info: MPD running with PID15733 Feb 18 20:30:10 volumio volumio[15505]: ,establishing connection Feb 18 20:30:10 volumio volumio[15505]: error: updateQueue error: null Feb 18 20:30:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:10 volumio go-librespot[15833]: go-librespot daemon starting... Feb 18 20:30:10 volumio volumio[15505]: info: Completed starting Core Plugins Feb 18 20:30:10 volumio volumio[15505]: info: ------------------------------------------- Feb 18 20:30:10 volumio volumio[15505]: info: ----- MyVolumio plugins startup ---- Feb 18 20:30:10 volumio volumio[15505]: info: ------------------------------------------- Feb 18 20:30:10 volumio volumio[15505]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30:10+07:00" level=debug msg="app state loaded" Feb 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:10 volumio volumio[15505]: error: updateQueue error: null Feb 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30: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 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30: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 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30: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 18 20:30:10 volumio go-librespot[15834]: time="2026-02-18T20:30:10+07:00" level=info msg="zeroconf server listening on port 46565" Feb 18 20:30:11 volumio go-librespot[15834]: time="2026-02-18T20:30:11+07:00" level=debug msg="obtained new client token: AAB6N0j9YKpClmrBeJNvvQrD9wbNpvutxT2MVq4p9AJDWCHXmJodHfJhCxXmwixlPcJuf14U9+4PwBK6Xo/2VomfINBu7eq4htk1HIxUHsgr7eTdk64STIp2yj33u89Vz07IARSrE0eShteZXy3IGY3zvbAdDan7vfYGChK5WGwoiEGS8P1Nhn4nlOST+TiQxmzsMORR1zQ5ZkZ1NhEj57u4Sa0a1XdbvFnTaF6rTZLl0aYIqFI/gfTwzg==" Feb 18 20:30:11 volumio go-librespot[15834]: time="2026-02-18T20:30:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:11 volumio go-librespot[15834]: time="2026-02-18T20:30:11+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:11 volumio go-librespot[15834]: time="2026-02-18T20:30:11+07:00" level=debug msg="completed challenge" Feb 18 20:30:11 volumio go-librespot[15834]: time="2026-02-18T20:30: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 18 20:30:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:12 volumio volumio[15505]: info: Initializing connection to go-librespot Websocket Feb 18 20:30:12 volumio volumio[15505]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:30:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 20:30:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:14 volumio go-librespot[15841]: go-librespot daemon starting... Feb 18 20:30:14 volumio go-librespot[15842]: time="2026-02-18T20:30:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:14 volumio go-librespot[15842]: time="2026-02-18T20:30:14+07:00" level=debug msg="app state loaded" Feb 18 20:30:14 volumio go-librespot[15842]: time="2026-02-18T20:30:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:15 volumio volumio[15505]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30: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 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30: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 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30: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 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+07:00" level=info msg="zeroconf server listening on port 35367" Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+07:00" level=debug msg="obtained new client token: AAAgJkLgDccjjnd5o3VQVxqYeXvMMXHuymPQT99UmBK88O3Se/wWwcV/AAT19zD58u8xK4EDZff8qLozXh/vH+iTZ+WyPo+ary/VmY1MjiGAUE8xZwPGpS7QJFs5AFQGEarWsxsvngeUIkUGvkE7JlmU8P2HQ/VPvKKf+hf9t8hTK0qFZ+NyvRlAIpoo7tEIwS/4WmiyiO/taLI5ff0zaVEeS8TXhk97fY3nHs52I4s8POFGdOS758x8pw==" Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+07:00" level=debug msg="completed challenge" Feb 18 20:30:15 volumio volumio[15505]: info: Initializing connection to go-librespot Websocket Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+07:00" level=debug msg="new websocket client" Feb 18 20:30:15 volumio go-librespot[15842]: time="2026-02-18T20:30:15+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 18 20:30:15 volumio volumio[15505]: info: Connection to go-librespot Websocket established Feb 18 20:30:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:15 volumio volumio[15505]: info: Connection to go-librespot Websocket closed Feb 18 20:30:19 volumio volumio[15505]: info: Getting Spotify volume Feb 18 20:30:19 volumio volumio[15505]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:30:19 volumio volumio[15505]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:30:19 volumio volumio[15505]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 20:30:19 volumio volumio[15505]: errno: -111, Feb 18 20:30:19 volumio volumio[15505]: code: 'ECONNREFUSED', Feb 18 20:30:19 volumio volumio[15505]: syscall: 'connect', Feb 18 20:30:19 volumio volumio[15505]: address: '127.0.0.1', Feb 18 20:30:19 volumio volumio[15505]: port: 9879, Feb 18 20:30:19 volumio volumio[15505]: response: undefined Feb 18 20:30:19 volumio volumio[15505]: } Feb 18 20:30:19 volumio volumio[15505]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:30:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 20:30:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:19 volumio go-librespot[15853]: go-librespot daemon starting... Feb 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+07:00" level=debug msg="app state loaded" Feb 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+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 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+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 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+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 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+07:00" level=info msg="zeroconf server listening on port 35389" Feb 18 20:30:19 volumio go-librespot[15862]: time="2026-02-18T20:30:19+07:00" level=debug msg="obtained new client token: AADBKo7DpJXI+hPoYXfhrxhRqz7iW/jyIug9mBOaTD07hE8vcaTo0URdcPB3rrbwDj3tFVWg8BJ8TlJf/nV+nmsJJuKqFrjFtnodXbs+gO5Ez0kNEu2l3DEyZZ635pi3JXb9joqn9704IAgdhlwjolyEPueonFs6vU2xQrVEtCjCST5VWT2+BWOfhhX6v4Uie2Enk6TblheITPaomlylc4I+FZdqqCtugJ7P33QNeFcBkfMuezyOfjTZTA==" Feb 18 20:30:20 volumio go-librespot[15862]: time="2026-02-18T20:30:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:20 volumio go-librespot[15862]: time="2026-02-18T20:30:20+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:20 volumio go-librespot[15862]: time="2026-02-18T20:30:20+07:00" level=debug msg="completed challenge" Feb 18 20:30:20 volumio go-librespot[15862]: time="2026-02-18T20:30: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 18 20:30:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:20 volumio sudo[15886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:29' Feb 18 20:30:20 volumio sudo[15886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:20 volumio sudo[15886]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:20 volumio volumio-remote-updater[25144]: [2026-02-18 20:30:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 20:30:20 volumio volumio-remote-updater[25144]: [2026-02-18 20:30:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 20:30:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 20:30:20 volumio systemd[1]: volumio.service: Consumed 53.011s CPU time. Feb 18 20:30:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:30:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:30:21 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22404. Feb 18 20:30:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:30:21 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 20:30:21 volumio systemd[1]: volumio.service: Consumed 53.011s CPU time. Feb 18 20:30:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 20:30:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:30:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 20:30:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:23 volumio go-librespot[15915]: go-librespot daemon starting... Feb 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+07:00" level=debug msg="app state loaded" Feb 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+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 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+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 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+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 18 20:30:23 volumio go-librespot[15916]: time="2026-02-18T20:30:23+07:00" level=info msg="zeroconf server listening on port 42627" Feb 18 20:30:24 volumio go-librespot[15916]: time="2026-02-18T20:30:24+07:00" level=debug msg="obtained new client token: AADhVm/NU9nnOk5WoVU8SARp/Pgyh2jUmSa0bPSAI/RZWSKFFx6ahGUDkrmZIRtxW7k0F79e8cgBz9gIQ3okvoLFQu7fXNK+AjQr8ar1Hqbwz9sQpKE4sb5ZVbNBH1bVlcw7h2LlEIdTwnz+XKO29DGMqll+debbvwNCFQygIno0ehHA6MDFzEHrwJWEGTIzt5BsOaoHRPa5I25RB5KnK1o+HYMsg5Yq6ecS0v5pM5vViuyMtaGnkFg=" Feb 18 20:30:24 volumio go-librespot[15916]: time="2026-02-18T20:30:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:24 volumio go-librespot[15916]: time="2026-02-18T20:30:24+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:24 volumio go-librespot[15916]: time="2026-02-18T20:30:24+07:00" level=debug msg="completed challenge" Feb 18 20:30:24 volumio go-librespot[15916]: time="2026-02-18T20:30: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 18 20:30:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:24 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:24 volumio volumio[15900]: info: ----- Volumio3 ---- Feb 18 20:30:24 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:24 volumio volumio[15900]: info: ----- System startup ---- Feb 18 20:30:24 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:25 volumio volumio-remote-updater[25144]: [2026-02-18 20:30:25] [connect] Successful connection Feb 18 20:30:26 volumio volumio[15900]: info: MYVOLUMIO Environment detected Feb 18 20:30:26 volumio volumio[15900]: info: Plugin folders cleanup Feb 18 20:30:26 volumio volumio[15900]: info: Scanning into folder /volumio/app/plugins/ Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category audio_interface Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category miscellanea Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category music_service Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category plugins.json Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category system_controller Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category user_interface Feb 18 20:30:26 volumio volumio[15900]: info: Scanning into folder /data/plugins/ Feb 18 20:30:26 volumio volumio[15900]: info: Scanning category music_service Feb 18 20:30:26 volumio volumio[15900]: info: Plugin folders cleanup completed Feb 18 20:30:26 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:26 volumio volumio[15900]: info: ----- Core plugins startup ---- Feb 18 20:30:26 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:26 volumio volumio[15900]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 20:30:26 volumio volumio[15900]: info: Adding plugin upnp to MyMusic Plugins Feb 18 20:30:26 volumio volumio[15900]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 20:30:26 volumio volumio[15900]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 20:30:26 volumio volumio[15900]: info: Loading plugins from folder /data/plugins/ Feb 18 20:30:26 volumio volumio[15900]: info: Loading plugin "system"... Feb 18 20:30:26 volumio volumio[15900]: info: Loading plugin "appearance"... Feb 18 20:30:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 20:30:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:27 volumio go-librespot[15935]: go-librespot daemon starting... Feb 18 20:30:27 volumio go-librespot[15936]: time="2026-02-18T20:30:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:27 volumio go-librespot[15936]: time="2026-02-18T20:30:27+07:00" level=debug msg="app state loaded" Feb 18 20:30:27 volumio go-librespot[15936]: time="2026-02-18T20:30:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "network"... Feb 18 20:30:28 volumio volumio[15900]: info: Refreshing Cached IP Addresses Feb 18 20:30:28 volumio sudo[15944]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:30:28 volumio sudo[15944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "services"... Feb 18 20:30:28 volumio sudo[15946]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "alsa_controller"... Feb 18 20:30:28 volumio sudo[15946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:28 volumio sudo[15944]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:28 volumio sudo[15946]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:28 volumio sudo[15953]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 20:30:28 volumio sudo[15953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30: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 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30: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 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30: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 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30:28+07:00" level=info msg="zeroconf server listening on port 37403" Feb 18 20:30:28 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "wizard"... Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "networkfs"... Feb 18 20:30:28 volumio volumio[15900]: info: Starting Udev Watcher for removable devices Feb 18 20:30:28 volumio volumio[15900]: info: Ignoring mount for partition: boot Feb 18 20:30:28 volumio volumio[15900]: info: Ignoring mount for partition: volumio Feb 18 20:30:28 volumio volumio[15900]: info: Ignoring mount for partition: volumio_data Feb 18 20:30:28 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "volumio_command_line_client"... Feb 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30:28+07:00" level=debug msg="obtained new client token: AADi2nbC5THLFokB5vBCAjaRdjNv7EKn881+tOchVvsQbMOJd4FV8Zx8j/3R3/yfKVUGaoqZyCl7sug1jHU3xwxHte7bGVnU7nujxDl8J9LW5XfRtTFGrv5xkpR5kljq2bI1E0yRR7bB+FmglEaVNoqZyQUPMtbGG24DmFzMljaisMUhHj6R7L2JeN1TEQpxuMSPHxYj20egZJfWOoOCcO0lHTc1FBGL/R/PWV6hp+VeveSDnavPuSxTNw==" Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "upnp"... Feb 18 20:30:28 volumio volumio[15900]: info: [1771421428718] Starting Upmpd Daemon Feb 18 20:30:28 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "my_music"... Feb 18 20:30:28 volumio volumio[15900]: info: Loading plugin "mpd"... Feb 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30:28+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:28 volumio go-librespot[15936]: time="2026-02-18T20:30:28+07:00" level=debug msg="completed challenge" Feb 18 20:30:29 volumio go-librespot[15936]: time="2026-02-18T20:30: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 18 20:30:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:29 volumio volumio[15900]: info: Loading plugin "upnp_browser"... Feb 18 20:30:31 volumio sudo[15953]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 20:30:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:32 volumio volumio[15900]: info: Starting UPNP Browser Feb 18 20:30:32 volumio volumio[15900]: info: Loading plugin "alarm-clock"... Feb 18 20:30:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:32 volumio go-librespot[15979]: go-librespot daemon starting... Feb 18 20:30:32 volumio go-librespot[15980]: time="2026-02-18T20:30:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:32 volumio go-librespot[15980]: time="2026-02-18T20:30:32+07:00" level=debug msg="app state loaded" Feb 18 20:30:32 volumio go-librespot[15980]: time="2026-02-18T20:30:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:32 volumio volumio[15900]: info: Loading plugin "airplay_emulation"... Feb 18 20:30:32 volumio volumio[15900]: info: Starting Shairport Sync Feb 18 20:30:32 volumio volumio[15900]: info: Loading plugin "last_100"... Feb 18 20:30:32 volumio volumio[15900]: info: Loading plugin "webradio"... Feb 18 20:30:32 volumio volumio[15900]: info: Loading plugin "i2s_dacs"... Feb 18 20:30:32 volumio volumio[15900]: info: Loading plugin "volumiodiscovery"... Feb 18 20:30:32 volumio go-librespot[15980]: time="2026-02-18T20:30: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:30:32 volumio go-librespot[15980]: time="2026-02-18T20:30:32+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 18 20:30:32 volumio go-librespot[15980]: time="2026-02-18T20:30:32+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 18 20:30:32 volumio volumio[15900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:30:32 volumio volumio[15900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:30:32 volumio volumio[15900]: *** WARNING *** For more information see Feb 18 20:30:32 volumio volumio[15900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:30:32 volumio volumio[15900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:30:32 volumio volumio[15900]: *** WARNING *** For more information see Feb 18 20:30:32 volumio node[15900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:30:32 volumio node[15900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:30:32 volumio node[15900]: *** WARNING *** For more information see Feb 18 20:30:32 volumio node[15900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:30:32 volumio volumio[15900]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 20:30:32 volumio node[15900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:30:32 volumio node[15900]: *** WARNING *** For more information see Feb 18 20:30:33 volumio volumio[15900]: info: Discovery: Started advertising with name: Volumio Feb 18 20:30:33 volumio go-librespot[15980]: time="2026-02-18T20:30:33+07:00" level=info msg="zeroconf server listening on port 44413" Feb 18 20:30:33 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:30:33 volumio volumio[15900]: info: Loading plugin "spop"... Feb 18 20:30:33 volumio go-librespot[15980]: time="2026-02-18T20:30:33+07:00" level=debug msg="obtained new client token: AAAMMIzVsleCbAKBo+ye+k36DXYnkAxE1qFeVK9+k0vcXh/fcz4TXAG1d0p1mAZla86xZAOvfGfQUQO1IG7VU/pJ0Ylu5nqtw+41jodONmVdi8DBsNlQkLuOWnNKoPTxLkusg0RDrVPKpDis84xKPNOk2DDBfQqaFdvcjKlZ0memb1if+RE+qloE7Jq+ORDlCqC41bZcSJRKnZuuTxoEKeDuMpkXu49zGoHuuEkdzYKBfK+7d28kOBWbQg==" Feb 18 20:30:33 volumio go-librespot[15980]: time="2026-02-18T20:30:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:33 volumio go-librespot[15980]: time="2026-02-18T20:30:33+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:33 volumio go-librespot[15980]: time="2026-02-18T20:30:33+07:00" level=debug msg="completed challenge" Feb 18 20:30:33 volumio go-librespot[15980]: time="2026-02-18T20:30: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 18 20:30:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:34 volumio volumio[15900]: info: Loading plugin "ytcr"... Feb 18 20:30:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 20:30:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:37 volumio go-librespot[15989]: go-librespot daemon starting... Feb 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30:37+07:00" level=debug msg="app state loaded" Feb 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:37 volumio volumio[15900]: info: Loading plugin "ytmusic"... Feb 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30:37+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 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30:37+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 18 20:30:37 volumio go-librespot[15990]: time="2026-02-18T20:30:37+07:00" level=info msg="zeroconf server listening on port 39745" Feb 18 20:30:38 volumio go-librespot[15990]: time="2026-02-18T20:30:38+07:00" level=debug msg="obtained new client token: AADBCOsNmGR61d+EpgTPMDhWbVaQTlMS75uQilNEFkUCENXXexFcpLe0B8WHLX3wQJj9RsHrUBbEEweQs3rhKRiQ3rCX1E2mf9bYaKQYp/scgSB0rgzXr2/1baW90vWMyYUJviELe+hmouiXQaDbFaGJXuRg2x/pb423L6ULeW3iawkCIk8JVubI3Dhsakmp2Eu0rvIy3FNVehQu+fU4JWTdV8omtxDB98r17i8XlB6xBkNw1HwgDEs=" Feb 18 20:30:38 volumio go-librespot[15990]: time="2026-02-18T20:30:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:38 volumio go-librespot[15990]: time="2026-02-18T20:30:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:30:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:38 volumio volumio-remote-updater[25144]: [2026-02-18 20:30:38] [connect] Successful connection Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "outputs"... Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "albumart"... Feb 18 20:30:38 volumio volumio[15900]: info: Plugin example_plugin is not enabled Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "inputs"... Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "updater_comm"... Feb 18 20:30:38 volumio volumio[15900]: info: Plugin mpdemulation is not enabled Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "rest_api"... Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "websocket"... Feb 18 20:30:38 volumio volumio[15900]: info: Starting Socket.io Server version 1.7.4 Feb 18 20:30:38 volumio volumio[15900]: info: Loading plugin "RoonBridge"... Feb 18 20:30:39 volumio volumio[15900]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 20:30:39 volumio volumio[15900]: info: Loading i18n strings for locale en Feb 18 20:30:39 volumio volumio[15900]: Updating browse sources language Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::initPlayerControls Feb 18 20:30:39 volumio volumio[16011]: Forking 3 albumart workers Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:30:39 volumio volumio[15900]: Express server listening on port 3000 Feb 18 20:30:39 volumio volumio[15900]: [Metrics] WebUI: 16s 72.79ms Feb 18 20:30:39 volumio volumio[15900]: info: CoreStateMachine::resetVolumioState Feb 18 20:30:39 volumio volumio[15900]: info: CoreStateMachine::getcurrentVolume Feb 18 20:30:39 volumio volumio[15900]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:30:40 volumio sudo[16053]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:30:40 volumio sudo[16053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:40 volumio sudo[16053]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:40 volumio sudo[16055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:30:40 volumio sudo[16055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:40 volumio sudo[16055]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:40 volumio volumio[15900]: info: Volumio Network Manager: Network status updated: 1 Feb 18 20:30:40 volumio volumio[15900]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::pushState Feb 18 20:30:40 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::updateTrackBlock Feb 18 20:30:40 volumio volumio[15900]: info: CorePlayQueue::getTrackBlock Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:30:40 volumio volumio-remote-updater[25144]: [2026-02-18 20:30:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771421438 101 Feb 18 20:30:40 volumio volumio[15900]: 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 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:40 volumio volumio[15900]: info: Reloading queue from file Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::setRepeat null single undefined Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::pushState Feb 18 20:30:40 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::setRandom null Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::pushState Feb 18 20:30:40 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:40 volumio volumio[15900]: info: Setting Device type: Raspberry PI Feb 18 20:30:40 volumio volumio[15900]: info: Completed loading Core Plugins Feb 18 20:30:40 volumio volumio[15900]: info: Preparing to generate the ALSA configuration file Feb 18 20:30:40 volumio volumio[15900]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:30:40 volumio volumio[15900]: info: CoreStateMachine::pushState Feb 18 20:30:40 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:40 volumio volumio[15900]: info: Asound.conf file unchanged, so no further update is needed Feb 18 20:30:40 volumio volumio[15900]: info: Output device has changed, restarting MPD Feb 18 20:30:40 volumio volumio[15900]: info: Output device has changed, restarting Shairport Sync Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:40 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:41 volumio sudo[16072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 20:30:41 volumio sudo[16072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:41 volumio sudo[16074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:30:41 volumio sudo[16074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:41 volumio volumio[15900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:30:41 volumio volumio[15900]: info: ___________ START PLUGINS ___________ Feb 18 20:30:41 volumio sudo[16076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:30:41 volumio sudo[16076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:41 volumio volumio[15900]: info: ControllerMpd::onStart: Initializing MPD Feb 18 20:30:41 volumio volumio[15900]: info: Creating MPD Configuration file Feb 18 20:30:41 volumio sudo[16074]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:41 volumio sudo[16072]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:41 volumio volumio[15900]: info: [1771421441175] CoreMusicLibrary::Adding element Media Servers Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:41 volumio volumio[15900]: info: UPNP Browser: Client initialized successfully Feb 18 20:30:41 volumio sudo[16085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:30:41 volumio sudo[16085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 20:30:41 volumio sudo[16085]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:41 volumio sudo[16087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:30:41 volumio sudo[16087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:41 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:30:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:30:41 volumio systemd[1]: mpd.service: Consumed 7.203s CPU time. Feb 18 20:30:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 20:30:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:30:41 volumio volumio[15900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:30:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:30:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:30:41 volumio volumio[15900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:41 volumio volumio[15900]: info: [1771421441512] CoreMusicLibrary::Adding element Last_100 Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:41 volumio volumio[15900]: info: [1771421441543] CoreMusicLibrary::Adding element Webradio Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:41 volumio go-librespot[16099]: go-librespot daemon starting... Feb 18 20:30:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:30:41 volumio volumio[15900]: info: Initializing BBC Radios Feb 18 20:30:41 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:30:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:30:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:30:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:30:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:30:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:30:41 volumio go-librespot[16101]: time="2026-02-18T20:30:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:41 volumio go-librespot[16101]: time="2026-02-18T20:30:41+07:00" level=debug msg="app state loaded" Feb 18 20:30:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:30:41 volumio go-librespot[16101]: time="2026-02-18T20:30:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:41 volumio volumio[15900]: info: Creating Spotify config file Feb 18 20:30:41 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:42 volumio sudo[16111]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 20:30:42 volumio sudo[16111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 20:30:42 volumio sudo[16111]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:42 volumio go-librespot[16101]: time="2026-02-18T20:30: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 18 20:30:42 volumio go-librespot[16101]: time="2026-02-18T20:30: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 18 20:30:42 volumio go-librespot[16101]: time="2026-02-18T20:30: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 18 20:30:42 volumio go-librespot[16101]: time="2026-02-18T20:30:42+07:00" level=info msg="zeroconf server listening on port 46299" Feb 18 20:30:42 volumio go-librespot[16101]: time="2026-02-18T20:30:42+07:00" level=debug msg="obtained new client token: AADQVMF4Vkoc4zF5F6C2QkXMfkBIi0jPw6UKIx1aoRYcUX3a67jfC58bKwPaUKgvBJVT6zlUjWqoVIjoI8pG9yjqm3ED6ya2DAZ68CD+JuKToIXkXmj3vLHDem5+7pl0CkSpbhWXx1OScrNHaVUh5ISLNk/iNpT2wlcZUa0i2qUQJAwDtAJJtv793g2PT3LksVj5VYoU4wMdLcTV91Ef4aX4OqRyGT+sJhVFjkwF5jWSMkX+c3R0TXQucA==" Feb 18 20:30:43 volumio go-librespot[16101]: time="2026-02-18T20:30:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:43 volumio volumio[16023]: Starting albumart workers Feb 18 20:30:43 volumio go-librespot[16101]: time="2026-02-18T20:30:43+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:43 volumio go-librespot[16101]: time="2026-02-18T20:30:43+07:00" level=debug msg="completed challenge" Feb 18 20:30:43 volumio go-librespot[16101]: time="2026-02-18T20:30:43+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 18 20:30:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:43 volumio volumio[16022]: Starting albumart workers Feb 18 20:30:43 volumio volumio[15900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:43 volumio volumio[15900]: info: [1771421443703] CoreMusicLibrary::Adding element YouTube Music Feb 18 20:30:43 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:43 volumio volumio[15900]: Cannot find translation for source YouTube Music Feb 18 20:30:43 volumio volumio[16021]: Starting albumart workers Feb 18 20:30:43 volumio volumio[15900]: info: Volumio Calling Home Feb 18 20:30:43 volumio sudo[16128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 20:30:43 volumio sudo[16128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:44 volumio sudo[16128]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:44 volumio volumio[15900]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:30:44 volumio volumio[15900]: info: Discovery: Found device Volumio Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:44 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:44 volumio volumio[15900]: info: MPD Permissions set Feb 18 20:30:44 volumio volumio[15900]: info: MPD Permissions set Feb 18 20:30:44 volumio volumio[15900]: info: Upmpdcli Daemon Started Feb 18 20:30:44 volumio volumio[15900]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:30:44 volumio volumio[15900]: info: Discovery: Found device Volumio Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:44 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:44 volumio volumio[15900]: info: Spotify config file written Feb 18 20:30:44 volumio volumio[15900]: 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 18 20:30:44 volumio volumio[15900]: info: Volumio called home Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:44 volumio sudo[16141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:30:44 volumio sudo[16141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:30:45 volumio volumio[15900]: info: No need to fix Spotify hosts Feb 18 20:30:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:45 volumio go-librespot[16154]: go-librespot daemon starting... Feb 18 20:30:45 volumio sudo[16141]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30:45+07:00" level=debug msg="app state loaded" Feb 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30:45+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 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30:45+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 18 20:30:45 volumio go-librespot[16157]: time="2026-02-18T20:30:45+07:00" level=info msg="zeroconf server listening on port 35847" Feb 18 20:30:46 volumio volumio[15900]: info: Starting Shairport Sync Feb 18 20:30:46 volumio volumio[15900]: info: Starting Shairport Sync Feb 18 20:30:46 volumio volumio[15900]: info: Starting Shairport Sync Feb 18 20:30:46 volumio sudo[16176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:30:46 volumio sudo[16176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:46 volumio sudo[16178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:30:46 volumio sudo[16178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:46 volumio sudo[16180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:30:46 volumio sudo[16180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:46 volumio go-librespot[16157]: time="2026-02-18T20:30:46+07:00" level=debug msg="obtained new client token: AAAU9Yb9lA6CQRwB93824f1e/bgEUJ7eZKZz+S8Cd4iVeg3efMXi/mqjyCLvntftsN7CbiTBnSkgw9/Tv0r+EhoahIbgG8KrZaTgq8h8GP5HDhvUQW8bsrsFEV4pHnIujysQ8cHRXXSH42I1vO6aQZ8F+L+QiwJT2POO0nIGrKwKsK2U4lZ/gXxrhl9ZunW301xrtcEmP36MUXWZxzjUlLjCgmCxHdaIvzQ7HWxjIt+9xiTw1wXBUHY=" Feb 18 20:30:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:30:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:30:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:30:46 volumio systemd[1]: shairport-sync.service: Consumed 2.239s CPU time. Feb 18 20:30:46 volumio go-librespot[16157]: time="2026-02-18T20:30:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:30:46 volumio sudo[16176]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:46 volumio sudo[16178]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:46 volumio volumio[15900]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:30:46 volumio volumio[15900]: SPOTIFY: BQCjMfOi_mQ64WfntJKtkspQE41X_BJJAwT9FCFVHH4unLQtZCtg_hmZ2b4MffCUekGG-e6SYZLHHPyXDz6zFONq0htW7xwdeaG69yWeEFK3e97rBZoDmX-6sKKNJ-2R8pL24jnHvLSjsstyP_WkgEjNQUOPyAvhiIPCuQNuV_qbcdULBNSnUBByVMzZzLHoOxHBZMtqPvva9ajNu0MHZfa6Dqu5_XuomSXIGvLUmfF87ElBFmLqgbqFf1Yc7UeZgjS4I-OAz7X6WYLVufl4qnUkcyk3eboPFwIK9Yw73CLS81V5LB3cXK_v Feb 18 20:30:46 volumio volumio[15900]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:30:46 volumio volumio[15900]: info: New Spotify access token = BQCjMfOi_mQ64WfntJKtkspQE41X_BJJAwT9FCFVHH4unLQtZCtg_hmZ2b4MffCUekGG-e6SYZLHHPyXDz6zFONq0htW7xwdeaG69yWeEFK3e97rBZoDmX-6sKKNJ-2R8pL24jnHvLSjsstyP_WkgEjNQUOPyAvhiIPCuQNuV_qbcdULBNSnUBByVMzZzLHoOxHBZMtqPvva9ajNu0MHZfa6Dqu5_XuomSXIGvLUmfF87ElBFmLqgbqFf1Yc7UeZgjS4I-OAz7X6WYLVufl4qnUkcyk3eboPFwIK9Yw73CLS81V5LB3cXK_v Feb 18 20:30:46 volumio go-librespot[16157]: time="2026-02-18T20:30:46+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:46 volumio go-librespot[16157]: time="2026-02-18T20:30:46+07:00" level=debug msg="completed challenge" Feb 18 20:30:46 volumio volumio[15900]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:30:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:30:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:30:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:30:46 volumio go-librespot[16157]: time="2026-02-18T20:30: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 18 20:30:46 volumio volumio[15900]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:46 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:46 volumio volumio[15900]: info: Shairport-Sync Started Feb 18 20:30:46 volumio volumio[15900]: Error adding Membership: Error: addMembership EINVAL Feb 18 20:30:46 volumio volumio[15900]: info: Shairport-Sync Started Feb 18 20:30:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:30:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:46 volumio sudo[16180]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:46 volumio volumio[15900]: info: Shairport-Sync Started Feb 18 20:30:46 volumio volumio[15900]: 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 18 20:30:47 volumio volumio[15900]: info: Spotify Successfully logged in Feb 18 20:30:47 volumio volumio[15900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:30:47 volumio volumio[15900]: info: [1771421447014] CoreMusicLibrary::Adding element Spotify Feb 18 20:30:47 volumio volumio[15900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:30:47 volumio volumio[15900]: Cannot find translation for source YouTube Music Feb 18 20:30:47 volumio volumio[15900]: Cannot find translation for source Spotify Feb 18 20:30:47 volumio volumio[15900]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 20:30:47 volumio volumio[15900]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:30:48 volumio volumio[15900]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:30:48 volumio volumio[15900]: info: CoreCommandRouter::volumioGetState Feb 18 20:30:48 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:48 volumio volumio[15900]: info: CoreStateMachine::pushState Feb 18 20:30:48 volumio volumio[15900]: info: CorePlayQueue::getTrack 0 Feb 18 20:30:48 volumio volumio[15900]: info: CoreCommandRouter::volumioPushState Feb 18 20:30:48 volumio volumio[15900]: info: go-librespot daemon successfully initialized Feb 18 20:30:49 volumio mpd[16125]: 2026-02-18T20:30:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 20:30:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 20:30:49 volumio sudo[16076]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:49 volumio sudo[16087]: pam_unix(sudo:session): session closed for user root Feb 18 20:30:49 volumio volumio[15900]: error: MPD error: The expression evaluated to a falsy value: Feb 18 20:30:49 volumio volumio[15900]: assert.ok(self.idling) Feb 18 20:30:49 volumio volumio[15900]: error: The expression evaluated to a falsy value: Feb 18 20:30:49 volumio volumio[15900]: assert.ok(self.idling) Feb 18 20:30:49 volumio volumio[15900]: info: MPD running with PID16125 Feb 18 20:30:49 volumio volumio[15900]: ,establishing connection Feb 18 20:30:49 volumio volumio[15900]: error: updateQueue error: null Feb 18 20:30:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 20:30:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:49 volumio volumio[15900]: info: Completed starting Core Plugins Feb 18 20:30:49 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:49 volumio volumio[15900]: info: ----- MyVolumio plugins startup ---- Feb 18 20:30:49 volumio volumio[15900]: info: ------------------------------------------- Feb 18 20:30:49 volumio volumio[15900]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 20:30:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:49 volumio go-librespot[16221]: go-librespot daemon starting... Feb 18 20:30:49 volumio volumio[15900]: error: updateQueue error: null Feb 18 20:30:49 volumio go-librespot[16222]: time="2026-02-18T20:30:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:49 volumio go-librespot[16222]: time="2026-02-18T20:30:49+07:00" level=debug msg="app state loaded" Feb 18 20:30:49 volumio go-librespot[16222]: time="2026-02-18T20:30:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+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 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+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 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+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 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+07:00" level=info msg="zeroconf server listening on port 34653" Feb 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+07:00" level=debug msg="obtained new client token: AAAhKjOmPpiwpgSxU/m/x17hrOgfb3Wo/BWQe6FsmVSJfevYAkKkLQxEn/1bvp00uCC0TcwiTo5uw/0FAevZpfg72CDuGL8aiq1fXfavne9XPk62mSoBaPnDV0itYpJ5EDuauL8yR5ZQI55VjS//jVDeTPxHWG6J1z5NO0WCVdXPfyi1x+a5qo3D3GtRI1LuE/cyY+A/0ZzLoUIbm501lGsbkbZczKe+6NKEZFZ684wg85FCdoxmTyUXlA==" Feb 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:50 volumio go-librespot[16222]: time="2026-02-18T20:30:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:30:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:51 volumio volumio[15900]: info: Initializing connection to go-librespot Websocket Feb 18 20:30:51 volumio volumio[15900]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:30:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 20:30:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:54 volumio go-librespot[16230]: go-librespot daemon starting... Feb 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+07:00" level=debug msg="app state loaded" Feb 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:54 volumio volumio[15900]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+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 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+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 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+07:00" level=info msg="zeroconf server listening on port 33245" Feb 18 20:30:54 volumio volumio[15900]: info: Initializing connection to go-librespot Websocket Feb 18 20:30:54 volumio go-librespot[16231]: time="2026-02-18T20:30:54+07:00" level=debug msg="new websocket client" Feb 18 20:30:55 volumio volumio[15900]: info: Connection to go-librespot Websocket established Feb 18 20:30:55 volumio go-librespot[16231]: time="2026-02-18T20:30:55+07:00" level=debug msg="obtained new client token: AADk5GLfyIXLvz/KLC1+Nmxwc12RWjv0joaorRxI6eq/s+kkR/dsmDRkYfuiLWXWeKwiXRS+EeG/9oxA+o/uG1Ao+AMt714qc9iAumgXb0bZgULeuOwb9LBkaf0bqVJu18ULbxs5TdA7ZXNpI20IVYGge2D1SxTVfsltvxw5XmgzM6PUOBl9GWG36K/R1Wp79OrunU+z6jfptkhWGMAOgalMaDT160oL8lCfeh5TB0ouwSs4rMLqJtk=" Feb 18 20:30:55 volumio go-librespot[16231]: time="2026-02-18T20:30:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:55 volumio go-librespot[16231]: time="2026-02-18T20:30:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:30:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:55 volumio volumio[15900]: info: Connection to go-librespot Websocket closed Feb 18 20:30:58 volumio volumio[15900]: info: Getting Spotify volume Feb 18 20:30:58 volumio volumio[15900]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:30:58 volumio volumio[15900]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:30:58 volumio volumio[15900]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 20:30:58 volumio volumio[15900]: errno: -111, Feb 18 20:30:58 volumio volumio[15900]: code: 'ECONNREFUSED', Feb 18 20:30:58 volumio volumio[15900]: syscall: 'connect', Feb 18 20:30:58 volumio volumio[15900]: address: '127.0.0.1', Feb 18 20:30:58 volumio volumio[15900]: port: 9879, Feb 18 20:30:58 volumio volumio[15900]: response: undefined Feb 18 20:30:58 volumio volumio[15900]: } Feb 18 20:30:58 volumio volumio[15900]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:30:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 20:30:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:30:58 volumio go-librespot[16250]: go-librespot daemon starting... Feb 18 20:30:58 volumio go-librespot[16251]: time="2026-02-18T20:30:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:30:58 volumio go-librespot[16251]: time="2026-02-18T20:30:58+07:00" level=debug msg="app state loaded" Feb 18 20:30:58 volumio go-librespot[16251]: time="2026-02-18T20:30:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+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 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+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 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+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 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+07:00" level=info msg="zeroconf server listening on port 32883" Feb 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+07:00" level=debug msg="obtained new client token: AAA2d339xwR4uqjLZOafSbcF1a4dt1T+NFWm0cxH20ykDU94/7VLFFHeiPggaQCyfqNYwkyKL0ceQvttm7AtZehfJnv4c5TN/C5607GLeTOq6fg7RzFYt7/vGLuLv4PpVMzRPe07rlaDNMwza2DbwEZY7giT9+a1ZCc2jsNWaXuMMaGcD1gvB7Idj52HwYaXsecHrecPMQgeN/Z/vIoEWeZcuYbNXAvDIKX+R0QfPNfmmRC/pRkD65PNug==" Feb 18 20:30:59 volumio sudo[16274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:29' Feb 18 20:30:59 volumio sudo[16274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+07:00" level=debug msg="completed keyexchange" Feb 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30:59+07:00" level=debug msg="completed challenge" Feb 18 20:30:59 volumio go-librespot[16251]: time="2026-02-18T20:30: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 18 20:30:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:30:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:30:59 volumio sudo[16274]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:00 volumio volumio-remote-updater[25144]: [2026-02-18 20:31:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 20:31:00 volumio volumio-remote-updater[25144]: [2026-02-18 20:31:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 20:31:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 20:31:00 volumio systemd[1]: volumio.service: Consumed 53.396s CPU time. Feb 18 20:31:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:31:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:31:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22405. Feb 18 20:31:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 20:31:00 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 20:31:00 volumio systemd[1]: volumio.service: Consumed 53.396s CPU time. Feb 18 20:31:00 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 20:31:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 20:31:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 20:31:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:03 volumio go-librespot[16302]: go-librespot daemon starting... Feb 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+07:00" level=debug msg="app state loaded" Feb 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+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 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+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 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+07:00" level=info msg="zeroconf server listening on port 44941" Feb 18 20:31:03 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:03 volumio volumio[16286]: info: ----- Volumio3 ---- Feb 18 20:31:03 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:03 volumio volumio[16286]: info: ----- System startup ---- Feb 18 20:31:03 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:03 volumio go-librespot[16303]: time="2026-02-18T20:31:03+07:00" level=debug msg="obtained new client token: AACgYO2n71OKkhhPu5cmSXe8Itmcnp9OHsKLy5OZyCgbdRxRwIBhUPJ0+2I2x501fyzAyLF9qy7hGQUHegEdgEnPjqOKcQ43OqwL754fUB9SQsp0wlcSpKGZqCFwXCF/RADBGEEUDfYAxZw0MWdR0uqLYZD8seeVYsVA5Io8iFU0mPWGw7gkcVczYByDuAfB6bC7cGsL0e7D85Rg35oraE/UwArZApcKHqkRI6YLw74ujTid7bWssYRzWQ==" Feb 18 20:31:04 volumio go-librespot[16303]: time="2026-02-18T20:31:04+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 18 20:31:04 volumio go-librespot[16303]: time="2026-02-18T20:31:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 20:31:04 volumio go-librespot[16303]: time="2026-02-18T20:31:04+07:00" level=debug msg="completed keyexchange" Feb 18 20:31:04 volumio go-librespot[16303]: time="2026-02-18T20:31:04+07:00" level=debug msg="completed challenge" Feb 18 20:31:04 volumio go-librespot[16303]: time="2026-02-18T20:31:04+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 18 20:31:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:05 volumio volumio-remote-updater[25144]: [2026-02-18 20:31:05] [connect] Successful connection Feb 18 20:31:05 volumio volumio[16286]: info: MYVOLUMIO Environment detected Feb 18 20:31:05 volumio volumio[16286]: info: Plugin folders cleanup Feb 18 20:31:05 volumio volumio[16286]: info: Scanning into folder /volumio/app/plugins/ Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category audio_interface Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category miscellanea Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category music_service Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category plugins.json Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category system_controller Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category user_interface Feb 18 20:31:05 volumio volumio[16286]: info: Scanning into folder /data/plugins/ Feb 18 20:31:05 volumio volumio[16286]: info: Scanning category music_service Feb 18 20:31:05 volumio volumio[16286]: info: Plugin folders cleanup completed Feb 18 20:31:05 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:05 volumio volumio[16286]: info: ----- Core plugins startup ---- Feb 18 20:31:05 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:05 volumio volumio[16286]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 20:31:05 volumio volumio[16286]: info: Adding plugin upnp to MyMusic Plugins Feb 18 20:31:05 volumio volumio[16286]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 20:31:05 volumio volumio[16286]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 20:31:05 volumio volumio[16286]: info: Loading plugins from folder /data/plugins/ Feb 18 20:31:05 volumio volumio[16286]: info: Loading plugin "system"... Feb 18 20:31:05 volumio volumio[16286]: info: Loading plugin "appearance"... Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "network"... Feb 18 20:31:07 volumio volumio[16286]: info: Refreshing Cached IP Addresses Feb 18 20:31:07 volumio sudo[16323]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:31:07 volumio sudo[16323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:07 volumio sudo[16325]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:31:07 volumio sudo[16323]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:07 volumio sudo[16325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "services"... Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "alsa_controller"... Feb 18 20:31:07 volumio sudo[16325]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:07 volumio sudo[16332]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 20:31:07 volumio sudo[16332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 20:31:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:07 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "wizard"... Feb 18 20:31:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "networkfs"... Feb 18 20:31:07 volumio go-librespot[16353]: go-librespot daemon starting... Feb 18 20:31:07 volumio go-librespot[16357]: time="2026-02-18T20:31:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:07 volumio go-librespot[16357]: time="2026-02-18T20:31:07+07:00" level=debug msg="app state loaded" Feb 18 20:31:07 volumio go-librespot[16357]: time="2026-02-18T20:31:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:07 volumio volumio[16286]: info: Starting Udev Watcher for removable devices Feb 18 20:31:07 volumio volumio[16286]: info: Ignoring mount for partition: boot Feb 18 20:31:07 volumio volumio[16286]: info: Ignoring mount for partition: volumio Feb 18 20:31:07 volumio volumio[16286]: info: Ignoring mount for partition: volumio_data Feb 18 20:31:07 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "volumio_command_line_client"... Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "upnp"... Feb 18 20:31:07 volumio volumio[16286]: info: [1771421467789] Starting Upmpd Daemon Feb 18 20:31:07 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "my_music"... Feb 18 20:31:07 volumio volumio[16286]: info: Loading plugin "mpd"... Feb 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+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 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+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 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+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 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+07:00" level=info msg="zeroconf server listening on port 44203" Feb 18 20:31:08 volumio volumio[16286]: info: Loading plugin "upnp_browser"... Feb 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+07:00" level=debug msg="obtained new client token: AACVXjz3uJRMrvIW9si5sRk2yxhoNoSoIxKn8m7Y12RjKu+BAR0RhCvfcAbVdFUN4zjqz3TQ1TRvpVY21fU6I5VRnO2cVolasWS3HWxPqb+/FLb12i+LxzZlCPDRrF4CMTbrEJ+wm10iLoBa3UoLMVOptktqqgBv/D2v3xyghMFJIv9XGg7h6cSP52eY8FfP2xRlq/WMsxW73FMzr0/wSEY4TktXwFMgVUi3e9UmI09WIFxcvOPii/YSZg==" Feb 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:08 volumio go-librespot[16357]: time="2026-02-18T20:31:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:43072->104.199.241.202:4070: read: connection reset by peer" Feb 18 20:31:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:10 volumio sudo[16332]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:11 volumio volumio[16286]: info: Starting UPNP Browser Feb 18 20:31:11 volumio volumio[16286]: info: Loading plugin "alarm-clock"... Feb 18 20:31:11 volumio volumio[16286]: info: Loading plugin "airplay_emulation"... Feb 18 20:31:11 volumio volumio[16286]: info: Starting Shairport Sync Feb 18 20:31:11 volumio volumio[16286]: info: Loading plugin "last_100"... Feb 18 20:31:11 volumio volumio[16286]: info: Loading plugin "webradio"... Feb 18 20:31:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 20:31:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:11 volumio go-librespot[16365]: go-librespot daemon starting... Feb 18 20:31:11 volumio go-librespot[16366]: time="2026-02-18T20:31:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:11 volumio go-librespot[16366]: time="2026-02-18T20:31:11+07:00" level=debug msg="app state loaded" Feb 18 20:31:11 volumio go-librespot[16366]: time="2026-02-18T20:31:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:11 volumio volumio[16286]: info: Loading plugin "i2s_dacs"... Feb 18 20:31:12 volumio volumio[16286]: info: Loading plugin "volumiodiscovery"... Feb 18 20:31:12 volumio volumio[16286]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:31:12 volumio volumio[16286]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:31:12 volumio volumio[16286]: *** WARNING *** For more information see Feb 18 20:31:12 volumio volumio[16286]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:31:12 volumio volumio[16286]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:31:12 volumio volumio[16286]: *** WARNING *** For more information see Feb 18 20:31:12 volumio node[16286]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 20:31:12 volumio node[16286]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:31:12 volumio node[16286]: *** WARNING *** For more information see Feb 18 20:31:12 volumio node[16286]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 20:31:12 volumio node[16286]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 20:31:12 volumio node[16286]: *** WARNING *** For more information see Feb 18 20:31:12 volumio volumio[16286]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 20:31:12 volumio volumio[16286]: info: Discovery: Started advertising with name: Volumio Feb 18 20:31:12 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 20:31:12 volumio volumio[16286]: info: Loading plugin "spop"... Feb 18 20:31:12 volumio go-librespot[16366]: time="2026-02-18T20:31:12+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 18 20:31:12 volumio go-librespot[16366]: time="2026-02-18T20:31:12+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 18 20:31:12 volumio go-librespot[16366]: time="2026-02-18T20:31:12+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 18 20:31:12 volumio go-librespot[16366]: time="2026-02-18T20:31:12+07:00" level=info msg="zeroconf server listening on port 44951" Feb 18 20:31:12 volumio go-librespot[16366]: time="2026-02-18T20:31:12+07:00" level=debug msg="obtained new client token: AABqSGrqnWrkzX1jKEhKAqQQwrLe6K6CbQa7SFsFLTT5vRnakINWJF8bT5hhm8rF7gH+6gHofWY40nUuhVPJervdi4JgwJzdNh6dzHsZ9/xZjsR9RXrMgFCrenotaDCowKJETxtKkC2rwJZKdDdaffwTRW2m5vSrScVxYepe90kZAqZqb8TUMAxrioQlyTCaTSJn9iv2Q1dUWL8WccSghduFSzD+XhqGCMjyZABoxzFXzMA6boxENEutkg==" Feb 18 20:31:12 volumio go-librespot[16366]: time="2026-02-18T20:31:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:13 volumio go-librespot[16366]: time="2026-02-18T20:31:13+07:00" level=debug msg="completed keyexchange" Feb 18 20:31:13 volumio go-librespot[16366]: time="2026-02-18T20:31:13+07:00" level=debug msg="completed challenge" Feb 18 20:31:13 volumio go-librespot[16366]: time="2026-02-18T20:31:13+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 18 20:31:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:14 volumio volumio[16286]: info: Loading plugin "ytcr"... Feb 18 20:31:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 20:31:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:16 volumio go-librespot[16376]: go-librespot daemon starting... Feb 18 20:31:16 volumio go-librespot[16377]: time="2026-02-18T20:31:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:16 volumio go-librespot[16377]: time="2026-02-18T20:31:16+07:00" level=debug msg="app state loaded" Feb 18 20:31:16 volumio go-librespot[16377]: time="2026-02-18T20:31:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:16 volumio volumio[16286]: info: Loading plugin "ytmusic"... Feb 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+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 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+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 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+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 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+07:00" level=info msg="zeroconf server listening on port 45723" Feb 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+07:00" level=debug msg="obtained new client token: AAAeyUAqBJsTAHzTDHZ3Pvnx0NQKoEUOC41NlNjHFkGYbdk/Dj88PjhysmHAOHt5A57HkUgk52sRtasOokwVonzWMcCb+y0GiVP3+/4fJX1NecK68jSQsoCR/1EA7M+bu6TwPyAzuNDcJj4p6QD0smgj6V16e35Dlry+3vOjfETMByv+fxVcFwDXM+C5DrzO+Wuff/gzKT7+AAxuHqONCZtKSZietj9DtsCmT6cj5ZXvfRxVRuxChg8=" Feb 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:17 volumio go-librespot[16377]: time="2026-02-18T20:31:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:31:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:17 volumio volumio-remote-updater[25144]: [2026-02-18 20:31:17] [connect] Successful connection Feb 18 20:31:17 volumio volumio[16286]: info: Loading plugin "outputs"... Feb 18 20:31:17 volumio volumio[16286]: info: Loading plugin "albumart"... Feb 18 20:31:17 volumio volumio[16286]: info: Plugin example_plugin is not enabled Feb 18 20:31:17 volumio volumio[16286]: info: Loading plugin "inputs"... Feb 18 20:31:17 volumio volumio[16286]: info: Loading plugin "updater_comm"... Feb 18 20:31:18 volumio volumio[16286]: info: Plugin mpdemulation is not enabled Feb 18 20:31:18 volumio volumio[16286]: info: Loading plugin "rest_api"... Feb 18 20:31:18 volumio volumio[16286]: info: Loading plugin "websocket"... Feb 18 20:31:18 volumio volumio[16286]: info: Starting Socket.io Server version 1.7.4 Feb 18 20:31:18 volumio volumio[16286]: info: Loading plugin "RoonBridge"... Feb 18 20:31:18 volumio volumio[16286]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 20:31:18 volumio volumio[16286]: info: Loading i18n strings for locale en Feb 18 20:31:18 volumio volumio[16286]: Updating browse sources language Feb 18 20:31:18 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:31:18 volumio volumio[16398]: Forking 3 albumart workers Feb 18 20:31:18 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::initPlayerControls Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: Express server listening on port 3000 Feb 18 20:31:19 volumio volumio[16286]: [Metrics] WebUI: 16s 155.40ms Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::resetVolumioState Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::getcurrentVolume Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:31:19 volumio sudo[16445]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:31:19 volumio sudo[16445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:19 volumio sudo[16442]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:31:19 volumio sudo[16442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:19 volumio sudo[16445]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:19 volumio sudo[16442]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:19 volumio volumio[16286]: info: Volumio Network Manager: Network status updated: 1 Feb 18 20:31:19 volumio volumio[16286]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::pushState Feb 18 20:31:19 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::volumioPushState Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::updateTrackBlock Feb 18 20:31:19 volumio volumio[16286]: info: CorePlayQueue::getTrackBlock Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:31:19 volumio volumio-remote-updater[25144]: [2026-02-18 20:31:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771421477 101 Feb 18 20:31:19 volumio volumio[16286]: 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 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:19 volumio volumio[16286]: info: Reloading queue from file Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::setRepeat null single undefined Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::pushState Feb 18 20:31:19 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::volumioPushState Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::setRandom null Feb 18 20:31:19 volumio volumio[16286]: info: CoreStateMachine::pushState Feb 18 20:31:19 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:19 volumio volumio[16286]: info: CoreCommandRouter::volumioPushState Feb 18 20:31:19 volumio volumio[16286]: info: Setting Device type: Raspberry PI Feb 18 20:31:19 volumio volumio[16286]: info: Completed loading Core Plugins Feb 18 20:31:19 volumio volumio[16286]: info: Preparing to generate the ALSA configuration file Feb 18 20:31:20 volumio volumio[16286]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:31:20 volumio volumio[16286]: info: CoreStateMachine::pushState Feb 18 20:31:20 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::volumioPushState Feb 18 20:31:20 volumio volumio[16286]: info: Asound.conf file unchanged, so no further update is needed Feb 18 20:31:20 volumio volumio[16286]: info: Output device has changed, restarting MPD Feb 18 20:31:20 volumio sudo[16459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 20:31:20 volumio sudo[16459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:20 volumio volumio[16286]: info: Output device has changed, restarting Shairport Sync Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:20 volumio sudo[16462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:31:20 volumio sudo[16462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:20 volumio sudo[16462]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:20 volumio sudo[16464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:31:20 volumio sudo[16464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:20 volumio volumio[16286]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:31:20 volumio volumio[16286]: info: ___________ START PLUGINS ___________ Feb 18 20:31:20 volumio sudo[16459]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:20 volumio volumio[16286]: info: ControllerMpd::onStart: Initializing MPD Feb 18 20:31:20 volumio volumio[16286]: info: Creating MPD Configuration file Feb 18 20:31:20 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:31:20 volumio volumio[16286]: info: [1771421480491] CoreMusicLibrary::Adding element Media Servers Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:31:20 volumio sudo[16472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 20:31:20 volumio sudo[16472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:20 volumio sudo[16472]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:20 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:31:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:31:20 volumio systemd[1]: mpd.service: Consumed 7.348s CPU time. Feb 18 20:31:20 volumio volumio[16286]: info: UPNP Browser: Client initialized successfully Feb 18 20:31:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 20:31:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:31:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:31:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:31:20 volumio sudo[16474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 20:31:20 volumio sudo[16474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:31:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:20 volumio volumio[16286]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:20 volumio go-librespot[16482]: go-librespot daemon starting... Feb 18 20:31:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:31:20 volumio go-librespot[16485]: time="2026-02-18T20:31:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:20 volumio go-librespot[16485]: time="2026-02-18T20:31:20+07:00" level=debug msg="app state loaded" Feb 18 20:31:20 volumio go-librespot[16485]: time="2026-02-18T20:31:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:20 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 20:31:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 20:31:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 20:31:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 20:31:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 20:31:20 volumio volumio[16286]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:31:20 volumio volumio[16286]: info: [1771421480881] CoreMusicLibrary::Adding element Last_100 Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:31:20 volumio volumio[16286]: info: [1771421480901] CoreMusicLibrary::Adding element Webradio Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:31:20 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:31:20 volumio volumio[16286]: info: Initializing BBC Radios Feb 18 20:31:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 20:31:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 20:31:21 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 20:31:21 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:21 volumio volumio[16286]: info: Creating Spotify config file Feb 18 20:31:21 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:21 volumio sudo[16497]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 20:31:21 volumio sudo[16497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 20:31:21 volumio sudo[16497]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:21 volumio go-librespot[16485]: time="2026-02-18T20:31:21+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 18 20:31:21 volumio go-librespot[16485]: time="2026-02-18T20:31:21+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 18 20:31:21 volumio go-librespot[16485]: time="2026-02-18T20:31:21+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 18 20:31:21 volumio go-librespot[16485]: time="2026-02-18T20:31:21+07:00" level=info msg="zeroconf server listening on port 40467" Feb 18 20:31:21 volumio go-librespot[16485]: time="2026-02-18T20:31:21+07:00" level=debug msg="obtained new client token: AACHh1cdbh6hwSeRN+f3P30ld6NJwpkdnW8JJDV+lOrURRbWho1XwCFfGeYpmRkLFb7t/ursENZzU9q+d2/eXmqapvtQDaybMv3j2fB3aJA5F/im8omdV1zQYBtsfstDv1THULCbraZO5xV3b3melyOR/6Jt2IwefV2LdjI+NMxeixVVa+8siU/JCVxpJ2dsplnp2kXktg2/8HpZ0KP4IC8LKD+7eZ5PFKz8AQZwMnU2uD7dvPUWa6nL0g==" Feb 18 20:31:22 volumio go-librespot[16485]: time="2026-02-18T20:31:22+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 18 20:31:22 volumio go-librespot[16485]: time="2026-02-18T20:31:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 20:31:22 volumio go-librespot[16485]: time="2026-02-18T20:31:22+07:00" level=debug msg="completed keyexchange" Feb 18 20:31:22 volumio go-librespot[16485]: time="2026-02-18T20:31:22+07:00" level=debug msg="completed challenge" Feb 18 20:31:22 volumio go-librespot[16485]: time="2026-02-18T20:31:22+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 18 20:31:22 volumio volumio[16286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:31:22 volumio volumio[16286]: info: [1771421482347] CoreMusicLibrary::Adding element YouTube Music Feb 18 20:31:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:22 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:31:22 volumio volumio[16286]: Cannot find translation for source YouTube Music Feb 18 20:31:22 volumio volumio[16286]: info: Volumio Calling Home Feb 18 20:31:22 volumio sudo[16514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 20:31:22 volumio sudo[16514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:22 volumio volumio[16408]: Starting albumart workers Feb 18 20:31:22 volumio sudo[16514]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:22 volumio volumio[16409]: Starting albumart workers Feb 18 20:31:22 volumio volumio[16410]: Starting albumart workers Feb 18 20:31:22 volumio volumio[16286]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:31:22 volumio volumio[16286]: info: Discovery: Found device Volumio Feb 18 20:31:22 volumio volumio[16286]: info: CoreCommandRouter::volumioGetState Feb 18 20:31:22 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:23 volumio volumio[16286]: info: MPD Permissions set Feb 18 20:31:23 volumio volumio[16286]: info: MPD Permissions set Feb 18 20:31:23 volumio volumio[16286]: info: Upmpdcli Daemon Started Feb 18 20:31:23 volumio volumio[16286]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 20:31:23 volumio volumio[16286]: info: Discovery: Found device Volumio Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::volumioGetState Feb 18 20:31:23 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:23 volumio volumio[16286]: info: Spotify config file written Feb 18 20:31:23 volumio sudo[16520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:31:23 volumio sudo[16520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:23 volumio go-librespot[16522]: go-librespot daemon starting... Feb 18 20:31:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:23 volumio sudo[16520]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:23 volumio go-librespot[16523]: time="2026-02-18T20:31:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:23 volumio go-librespot[16523]: time="2026-02-18T20:31:23+07:00" level=debug msg="app state loaded" Feb 18 20:31:23 volumio go-librespot[16523]: time="2026-02-18T20:31:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:23 volumio volumio[16286]: 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 18 20:31:23 volumio volumio[16286]: info: Volumio called home Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:31:23 volumio volumio[16286]: info: No need to fix Spotify hosts Feb 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31:24+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 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31:24+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 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31:24+07:00" level=info msg="zeroconf server listening on port 46151" Feb 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31:24+07:00" level=debug msg="obtained new client token: AACA3tpqG6TDWp8ItrpAuD0f97lwdqp/Lv8oUe/zbdY7iambwnlFqZOkvmjNbSWrCSP4POO8Jwe94GJpT2DuoD0Gx/F+UnLGgWPVzqFb9nSgDSm3sz7TOKAvCCnG3A5nJW0ZwSiO7TuRqiIHLvMjaWIU4gVlZWPxJA1C9LH2qzRpjHX62Vhg1jsL2tVE6zEWi/5uDv2qaNPUBBC8/EwHZYo+hDC0oxBEjq62PxtLuV2f4yLL0CEtdBtwWw==" Feb 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:24 volumio go-librespot[16523]: time="2026-02-18T20:31:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:31:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:25 volumio volumio[16286]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:31:25 volumio volumio[16286]: SPOTIFY: BQDgTljBBvi4BtE-XvGp7GpWPfKZgs1HEj1Jxb_U5tCTM-FOzWCsx0RAN_SeH-QIjGywhSt4UIbOWSoUInRkjiwImgJRYAZI9ey7uIDU-bFfOWad6K1LlGlC4maMEco5HFLcpTUfDrPraf18D0snMFHBt4aN_GimiPC8IlvsdDkgjeezweZiaIaqumfcQJ8qg3Rlw66TDbOfGtXU3ZNTd2Bur7buEWOI0UlD4ihSRswrhXiAUntjTe-1w6Ro12DtotyfPulyEXrL2PRUdXOKwL0-wh5vWO71vSfm_pbJXdA4abDTc9WoyzUk Feb 18 20:31:25 volumio volumio[16286]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:31:25 volumio volumio[16286]: info: New Spotify access token = BQDgTljBBvi4BtE-XvGp7GpWPfKZgs1HEj1Jxb_U5tCTM-FOzWCsx0RAN_SeH-QIjGywhSt4UIbOWSoUInRkjiwImgJRYAZI9ey7uIDU-bFfOWad6K1LlGlC4maMEco5HFLcpTUfDrPraf18D0snMFHBt4aN_GimiPC8IlvsdDkgjeezweZiaIaqumfcQJ8qg3Rlw66TDbOfGtXU3ZNTd2Bur7buEWOI0UlD4ihSRswrhXiAUntjTe-1w6Ro12DtotyfPulyEXrL2PRUdXOKwL0-wh5vWO71vSfm_pbJXdA4abDTc9WoyzUk Feb 18 20:31:25 volumio volumio[16286]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:31:25 volumio volumio[16286]: info: Starting Shairport Sync Feb 18 20:31:25 volumio volumio[16286]: info: Starting Shairport Sync Feb 18 20:31:25 volumio volumio[16286]: info: Starting Shairport Sync Feb 18 20:31:25 volumio sudo[16559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:31:25 volumio sudo[16559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:25 volumio sudo[16561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:31:25 volumio sudo[16561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:25 volumio sudo[16563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 20:31:25 volumio sudo[16563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:31:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:31:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:31:25 volumio systemd[1]: shairport-sync.service: Consumed 2.284s CPU time. Feb 18 20:31:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:31:25 volumio sudo[16559]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:25 volumio volumio[16286]: info: CoreCommandRouter::volumioGetState Feb 18 20:31:25 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 20:31:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 20:31:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:31:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 20:31:25 volumio sudo[16563]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:25 volumio sudo[16561]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:25 volumio volumio[16286]: info: Shairport-Sync Started Feb 18 20:31:25 volumio volumio[16286]: Error adding Membership: Error: addMembership EINVAL Feb 18 20:31:26 volumio volumio[16286]: info: Shairport-Sync Started Feb 18 20:31:26 volumio volumio[16286]: info: Shairport-Sync Started Feb 18 20:31:26 volumio volumio[16286]: 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 18 20:31:26 volumio volumio[16286]: info: Spotify Successfully logged in Feb 18 20:31:26 volumio volumio[16286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:31:26 volumio volumio[16286]: info: [1771421486091] CoreMusicLibrary::Adding element Spotify Feb 18 20:31:26 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:31:26 volumio volumio[16286]: Cannot find translation for source YouTube Music Feb 18 20:31:26 volumio volumio[16286]: Cannot find translation for source Spotify Feb 18 20:31:26 volumio volumio[16286]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 20:31:26 volumio volumio[16286]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 20:31:26 volumio volumio[16286]: info: VolumeController:: Volume=100 Mute =false Feb 18 20:31:26 volumio volumio[16286]: info: CoreCommandRouter::volumioGetState Feb 18 20:31:26 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:26 volumio volumio[16286]: info: CoreStateMachine::pushState Feb 18 20:31:26 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:26 volumio volumio[16286]: info: CoreCommandRouter::volumioPushState Feb 18 20:31:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 20:31:28 volumio volumio[16286]: info: go-librespot daemon successfully initialized Feb 18 20:31:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:28 volumio go-librespot[16600]: go-librespot daemon starting... Feb 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31:28+07:00" level=debug msg="app state loaded" Feb 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:28 volumio mpd[16511]: 2026-02-18T20:31:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 20:31:28 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 20:31:28 volumio sudo[16464]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:28 volumio sudo[16474]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31: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 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31: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 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31: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 18 20:31:28 volumio go-librespot[16601]: time="2026-02-18T20:31:28+07:00" level=info msg="zeroconf server listening on port 43967" Feb 18 20:31:29 volumio volumio[16286]: error: MPD error: The expression evaluated to a falsy value: Feb 18 20:31:29 volumio volumio[16286]: assert.ok(self.idling) Feb 18 20:31:29 volumio volumio[16286]: error: The expression evaluated to a falsy value: Feb 18 20:31:29 volumio volumio[16286]: assert.ok(self.idling) Feb 18 20:31:29 volumio volumio[16286]: error: updateQueue error: null Feb 18 20:31:29 volumio volumio[16286]: info: MPD running with PID16511 Feb 18 20:31:29 volumio volumio[16286]: ,establishing connection Feb 18 20:31:29 volumio go-librespot[16601]: time="2026-02-18T20:31:29+07:00" level=debug msg="obtained new client token: AABdKAeLy7FCqDrHeXp1tBIaA1imp32bhw/fnswV857Bk4RECfOD/BlxWDczc8UgsrZCBgygMMQrbON5hLclb/c8kPMzKpJknjsEZOwBXa5MckI5fjWhgFoMi351KNrVvqtdQV11xE866Y4SFJfxL1nucuK9p1bVdS3CzxrkY1/3HEYWcLadIt9HEjqkFpL2HKCHBrm92CF0+R9Sg1FhHIN/sHPct+4mQtxLe3+c669Hgda+fdCa4no=" Feb 18 20:31:29 volumio volumio[16286]: info: Completed starting Core Plugins Feb 18 20:31:29 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:29 volumio volumio[16286]: info: ----- MyVolumio plugins startup ---- Feb 18 20:31:29 volumio volumio[16286]: info: ------------------------------------------- Feb 18 20:31:29 volumio volumio[16286]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 20:31:29 volumio volumio[16286]: error: updateQueue error: null Feb 18 20:31:29 volumio go-librespot[16601]: time="2026-02-18T20:31:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:29 volumio go-librespot[16601]: time="2026-02-18T20:31:29+07:00" level=debug msg="completed keyexchange" Feb 18 20:31:29 volumio go-librespot[16601]: time="2026-02-18T20:31:29+07:00" level=debug msg="completed challenge" Feb 18 20:31:29 volumio go-librespot[16601]: time="2026-02-18T20:31: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 18 20:31:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:31 volumio volumio[16286]: info: Initializing connection to go-librespot Websocket Feb 18 20:31:31 volumio volumio[16286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:31:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 18 20:31:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:32 volumio go-librespot[16613]: go-librespot daemon starting... Feb 18 20:31:32 volumio go-librespot[16614]: time="2026-02-18T20:31:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:32 volumio go-librespot[16614]: time="2026-02-18T20:31:32+07:00" level=debug msg="app state loaded" Feb 18 20:31:32 volumio go-librespot[16614]: time="2026-02-18T20:31:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+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 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+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 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+07:00" level=info msg="zeroconf server listening on port 46121" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+07:00" level=debug msg="obtained new client token: AADgcL9oHhoDRcSoU5Mh8uQJO/ohdyvQatZLKT15QmcLd60SjmP0U7EFgAd4bItpYkgEAyYoNtB1i6MatGyHa8N2vBV44HUphcDoHM6YDjkoD5f1EZGEnWEBGweviH2gSWCEFTk4RUbpyStFlHnW0UBpEQ0OhDK4667iMBhjKnNEXmCbHatxs5JMdzeOTH5xQawd6+oUuSnhFv9P8LrcFnVAJfEVDeQ8/XvfilmMgsgxSyNZpWhIDWI7lw==" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+07:00" level=debug msg="completed keyexchange" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31:33+07:00" level=debug msg="completed challenge" Feb 18 20:31:33 volumio go-librespot[16614]: time="2026-02-18T20:31: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 18 20:31:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:33 volumio volumio[16286]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 20:31:34 volumio volumio[16286]: info: Initializing connection to go-librespot Websocket Feb 18 20:31:34 volumio volumio[16286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 20:31:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 18 20:31:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:36 volumio go-librespot[16622]: go-librespot daemon starting... Feb 18 20:31:36 volumio go-librespot[16623]: time="2026-02-18T20:31:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:36 volumio go-librespot[16623]: time="2026-02-18T20:31:36+07:00" level=debug msg="app state loaded" Feb 18 20:31:36 volumio go-librespot[16623]: time="2026-02-18T20:31:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:37 volumio volumio[16286]: info: Initializing connection to go-librespot Websocket Feb 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+07:00" level=debug msg="new websocket client" Feb 18 20:31:37 volumio volumio[16286]: info: Connection to go-librespot Websocket established Feb 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+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 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+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 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+07:00" level=info msg="zeroconf server listening on port 46651" Feb 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+07:00" level=debug msg="obtained new client token: AACsMkmgPz3Njr10V/PGbBwKnmt+GuGr/KiSp97ikPX9/sEHdRzuZE4Gzeia/cgN0Ke+cii3wZ3ZLKW6dZlZ+4/nkGVf4jGKfWBljifggquiBPxm8QK/hcXb+GMkTrKS804nILurxsQVJFRVNVedvSqBu/bmiUDLnTskSmK3Tqb+hj2mG+8+YI05vuPab2WM8PFoeAPW6hCa01MTAn5VTl072U/nFuudFOc4OrUlxXnLDUs3tPsq3Op6tg==" Feb 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+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 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 20:31:37 volumio go-librespot[16623]: time="2026-02-18T20:31:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 20:31:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:37 volumio volumio[16286]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 20:31:37 volumio volumio[16286]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 20:31:39 volumio volumio[16286]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 20:31:39 volumio volumio[16286]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 20:31:39 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:39 volumio volumio[16286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 20:31:39 volumio volumio[16286]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 20:31:39 volumio volumio[16286]: info: MyVolumio login type: Token Feb 18 20:31:39 volumio volumio[16286]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 20:31:39 volumio volumio[16286]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 20:31:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 18 20:31:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:31:41 volumio go-librespot[16644]: go-librespot daemon starting... Feb 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31:41+07:00" level=debug msg="app state loaded" Feb 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:31:41 volumio volumio[16286]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 20:31:41 volumio volumio[16286]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 20:31:41 volumio volumio[16286]: info: Streaming services startup Feb 18 20:31:41 volumio volumio[16286]: info: Starting Streaming Daemon Feb 18 20:31:41 volumio sudo[16653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 20:31:41 volumio sudo[16653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:31:41 volumio volumio[16286]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31: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 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31: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 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31: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 18 20:31:41 volumio sudo[16653]: pam_unix(sudo:session): session closed for user root Feb 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31:41+07:00" level=info msg="zeroconf server listening on port 41419" Feb 18 20:31:41 volumio volumio[16286]: info: Getting Spotify volume Feb 18 20:31:41 volumio volumio[16286]: info: Connection to go-librespot Websocket closed Feb 18 20:31:41 volumio volumio[16286]: error: Cannot start Volumio Streaming Daemon Feb 18 20:31:41 volumio volumio[16286]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 20:31:41 volumio volumio[16286]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 20:31:41 volumio volumio[16286]: 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 18 20:31:41 volumio go-librespot[16645]: time="2026-02-18T20:31:41+07:00" level=debug msg="obtained new client token: AAC8cP4NNTWnLiKb/ZhCN0fzti5ukD5aySZZBOyx5SY2x9k2cMGORwVO35MCl6A5sBpEWZhYhs4EB4YgXwyL1rBW9LNLmf1XOG5Nm4VBN5kQgaCpSzhjfZl4cw70S0Eh4p77Bnmor3MYiaB852M3ew1Z6oNdB0os+CWLk7edppKO7z/1ZG0+/DdyowE1GIAXcqgOsIBDWyPnOTZunSabop0wEGI3hxEoOoVvScxYhXJoyctjk15r400J4A==" Feb 18 20:31:42 volumio volumio[16286]: info: CoreCommandRouter::volumioGetState Feb 18 20:31:42 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:42 volumio go-librespot[16645]: time="2026-02-18T20:31:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 20:31:42 volumio volumio[16286]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 20:31:42 volumio volumio[16286]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 20:31:42 volumio volumio[16286]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 20:31:42 volumio volumio[16286]: info: Aligning Spotify Volume to Volumio Volume Feb 18 20:31:42 volumio volumio[16286]: info: CoreCommandRouter::volumioGetState Feb 18 20:31:42 volumio volumio[16286]: info: CorePlayQueue::getTrack 0 Feb 18 20:31:42 volumio volumio[16286]: info: Setting Spotify Volume from Volumio: 100 Feb 18 20:31:42 volumio go-librespot[16645]: time="2026-02-18T20:31:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 20:31:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 20:31:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 20:31:42 volumio volumio[16286]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:31:42 volumio volumio[16286]: Error: socket hang up Feb 18 20:31:42 volumio volumio[16286]: at connResetException (node:internal/errors:720:14) Feb 18 20:31:42 volumio volumio[16286]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 20:31:42 volumio volumio[16286]: at Socket.emit (node:events:526:35) Feb 18 20:31:42 volumio volumio[16286]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 20:31:42 volumio volumio[16286]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 20:31:42 volumio volumio[16286]: code: 'ECONNRESET', Feb 18 20:31:42 volumio volumio[16286]: response: undefined Feb 18 20:31:42 volumio volumio[16286]: } Feb 18 20:31:42 volumio volumio[16286]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:31:43 volumio sudo[16673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:30' Feb 18 20:31:43 volumio sudo[16673]: 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"