Feb 19 03:00:00 volumio volumio[27019]: info: Loading plugin "ytmusic"... Feb 19 03:00:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 19 03:00:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:01 volumio go-librespot[27110]: go-librespot daemon starting... Feb 19 03:00:01 volumio go-librespot[27111]: time="2026-02-19T03:00:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:01 volumio go-librespot[27111]: time="2026-02-19T03:00:01+07:00" level=debug msg="app state loaded" Feb 19 03:00:01 volumio go-librespot[27111]: time="2026-02-19T03:00:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:01 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:01] [connect] Successful connection Feb 19 03:00:01 volumio volumio[27019]: info: Loading plugin "outputs"... Feb 19 03:00:01 volumio volumio[27019]: info: Loading plugin "albumart"... Feb 19 03:00:01 volumio volumio[27019]: info: Plugin example_plugin is not enabled Feb 19 03:00:01 volumio volumio[27019]: info: Loading plugin "inputs"... Feb 19 03:00:01 volumio volumio[27019]: info: Loading plugin "updater_comm"... Feb 19 03:00:01 volumio go-librespot[27111]: time="2026-02-19T03:00:01+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 19 03:00:01 volumio go-librespot[27111]: time="2026-02-19T03:00:01+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 19 03:00:01 volumio go-librespot[27111]: time="2026-02-19T03:00:01+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 19 03:00:02 volumio go-librespot[27111]: time="2026-02-19T03:00:02+07:00" level=info msg="zeroconf server listening on port 41881" Feb 19 03:00:02 volumio volumio[27019]: info: Plugin mpdemulation is not enabled Feb 19 03:00:02 volumio volumio[27019]: info: Loading plugin "rest_api"... Feb 19 03:00:02 volumio volumio[27019]: info: Loading plugin "websocket"... Feb 19 03:00:02 volumio go-librespot[27111]: time="2026-02-19T03:00:02+07:00" level=debug msg="obtained new client token: AADPyFmRS5RLOyJGpIfvNIu30Z6/ehWAUO8Ma7CwD09928TUim1ScevCXbUjtp161C8IrcsTw0/c5wq5qhz40QOyGrXdIVDZ42tnmLKVw9LYo/6hYr7Ldqw4I6baZ8O4yLZbXoqKPl5mhZ7Qm/lfRU0n391odEJ3A2IFNIDfcXWxq4+e7a2IQfzr4ysS2gA8UOIu96+8WTkQ2WZGINMxemYv6+R7TPvqiq8yGrR4JsuTKCUJBY3uq1Q=" Feb 19 03:00:02 volumio volumio[27019]: info: Starting Socket.io Server version 1.7.4 Feb 19 03:00:02 volumio volumio[27019]: info: Loading plugin "RoonBridge"... Feb 19 03:00:02 volumio go-librespot[27111]: time="2026-02-19T03:00:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:02 volumio go-librespot[27111]: time="2026-02-19T03:00:02+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:02 volumio go-librespot[27111]: time="2026-02-19T03:00:02+07:00" level=debug msg="completed challenge" Feb 19 03:00:02 volumio go-librespot[27111]: time="2026-02-19T03:00:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:00:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:02 volumio volumio[27019]: info: Applying required configuration parameters for plugin RoonBridge Feb 19 03:00:02 volumio volumio[27019]: info: Loading i18n strings for locale en Feb 19 03:00:02 volumio volumio[27019]: Updating browse sources language Feb 19 03:00:02 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::initPlayerControls Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:00:03 volumio volumio[27132]: Forking 3 albumart workers Feb 19 03:00:03 volumio volumio[27019]: Express server listening on port 3000 Feb 19 03:00:03 volumio volumio[27019]: [Metrics] WebUI: 16s 33.96ms Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::resetVolumioState Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::getcurrentVolume Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:00:03 volumio sudo[27174]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 03:00:03 volumio sudo[27176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 03:00:03 volumio sudo[27174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:03 volumio sudo[27176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:03 volumio volumio[27019]: info: Volumio Network Manager: Network status updated: 1 Feb 19 03:00:03 volumio sudo[27174]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:03 volumio sudo[27176]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:03 volumio volumio[27019]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::pushState Feb 19 03:00:03 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::updateTrackBlock Feb 19 03:00:03 volumio volumio[27019]: info: CorePlayQueue::getTrackBlock Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:00:03 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771444801 101 Feb 19 03:00:03 volumio volumio[27019]: 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 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:03 volumio volumio[27019]: info: Reloading queue from file Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::setRepeat null single undefined Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::pushState Feb 19 03:00:03 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::setRandom null Feb 19 03:00:03 volumio volumio[27019]: info: CoreStateMachine::pushState Feb 19 03:00:03 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:03 volumio volumio[27019]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:03 volumio volumio[27019]: info: Setting Device type: Raspberry PI Feb 19 03:00:04 volumio volumio[27019]: info: Completed loading Core Plugins Feb 19 03:00:04 volumio volumio[27019]: info: Preparing to generate the ALSA configuration file Feb 19 03:00:04 volumio volumio[27019]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:00:04 volumio volumio[27019]: info: CoreStateMachine::pushState Feb 19 03:00:04 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:04 volumio volumio[27019]: info: Asound.conf file unchanged, so no further update is needed Feb 19 03:00:04 volumio volumio[27019]: info: Output device has changed, restarting MPD Feb 19 03:00:04 volumio volumio[27019]: info: Output device has changed, restarting Shairport Sync Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:04 volumio sudo[27192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 19 03:00:04 volumio sudo[27197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 03:00:04 volumio sudo[27192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:04 volumio sudo[27197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:04 volumio volumio[27019]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:00:04 volumio volumio[27019]: info: ___________ START PLUGINS ___________ Feb 19 03:00:04 volumio sudo[27195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 03:00:04 volumio volumio[27019]: info: ControllerMpd::onStart: Initializing MPD Feb 19 03:00:04 volumio volumio[27019]: info: Creating MPD Configuration file Feb 19 03:00:04 volumio sudo[27195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:04 volumio sudo[27195]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:04 volumio volumio[27019]: info: [1771444804392] CoreMusicLibrary::Adding element Media Servers Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:04 volumio sudo[27206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 03:00:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 19 03:00:04 volumio sudo[27206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:04 volumio volumio[27019]: info: UPNP Browser: Client initialized successfully Feb 19 03:00:04 volumio sudo[27206]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:04 volumio sudo[27192]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:04 volumio sudo[27208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 03:00:04 volumio sudo[27208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:04 volumio volumio[27019]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:04 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 03:00:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 03:00:04 volumio systemd[1]: mpd.service: Consumed 7.195s CPU time. Feb 19 03:00:04 volumio volumio[27019]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:04 volumio volumio[27019]: info: [1771444804627] CoreMusicLibrary::Adding element Last_100 Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:04 volumio volumio[27019]: info: [1771444804638] CoreMusicLibrary::Adding element Webradio Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 03:00:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:00:04 volumio volumio[27019]: info: Initializing BBC Radios Feb 19 03:00:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 03:00:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 03:00:04 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 03:00:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 03:00:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 03:00:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 03:00:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 03:00:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 03:00:04 volumio volumio[27019]: info: Creating Spotify config file Feb 19 03:00:04 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:05 volumio sudo[27235]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 19 03:00:05 volumio sudo[27235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 19 03:00:05 volumio sudo[27235]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 19 03:00:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:05 volumio go-librespot[27238]: go-librespot daemon starting... Feb 19 03:00:05 volumio go-librespot[27239]: time="2026-02-19T03:00:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:06 volumio volumio[27019]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:06 volumio volumio[27019]: info: [1771444806041] CoreMusicLibrary::Adding element YouTube Music Feb 19 03:00:06 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:06 volumio volumio[27019]: Cannot find translation for source YouTube Music Feb 19 03:00:06 volumio volumio[27019]: info: Volumio Calling Home Feb 19 03:00:06 volumio sudo[27246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 19 03:00:06 volumio sudo[27246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:06 volumio go-librespot[27239]: time="2026-02-19T03:00:06+07:00" level=info msg="zeroconf server listening on port 39911" Feb 19 03:00:06 volumio sudo[27246]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:06 volumio volumio[27147]: Starting albumart workers Feb 19 03:00:06 volumio volumio[27143]: Starting albumart workers Feb 19 03:00:06 volumio volumio[27019]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 03:00:06 volumio volumio[27019]: info: Discovery: Found device Volumio Feb 19 03:00:06 volumio volumio[27019]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:06 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:07 volumio volumio[27019]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 03:00:07 volumio volumio[27019]: info: Discovery: Found device Volumio Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:07 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:07 volumio volumio[27019]: info: MPD Permissions set Feb 19 03:00:07 volumio volumio[27019]: info: MPD Permissions set Feb 19 03:00:07 volumio volumio[27019]: info: Upmpdcli Daemon Started Feb 19 03:00:07 volumio volumio[27146]: Starting albumart workers Feb 19 03:00:07 volumio volumio[27019]: info: Volumio called home Feb 19 03:00:07 volumio volumio[27019]: info: Spotify config file written Feb 19 03:00:07 volumio sudo[27254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 19 03:00:07 volumio sudo[27254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:07 volumio volumio[27019]: 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 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 19 03:00:07 volumio systemd[1]: go-librespot-daemon.service: Killing process 27241 (go-librespot) with signal SIGKILL. Feb 19 03:00:07 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 19 03:00:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio go-librespot[27261]: go-librespot daemon starting... Feb 19 03:00:07 volumio sudo[27254]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:07 volumio volumio[27019]: info: No need to fix Spotify hosts Feb 19 03:00:07 volumio go-librespot[27263]: time="2026-02-19T03:00:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:07 volumio go-librespot[27263]: time="2026-02-19T03:00:07+07:00" level=debug msg="app state loaded" Feb 19 03:00:07 volumio go-librespot[27263]: time="2026-02-19T03:00:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:08 volumio go-librespot[27263]: time="2026-02-19T03:00: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 19 03:00:08 volumio go-librespot[27263]: time="2026-02-19T03:00: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 19 03:00:08 volumio go-librespot[27263]: time="2026-02-19T03:00: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 19 03:00:08 volumio go-librespot[27263]: time="2026-02-19T03:00:08+07:00" level=info msg="zeroconf server listening on port 33607" Feb 19 03:00:08 volumio go-librespot[27263]: time="2026-02-19T03:00:08+07:00" level=debug msg="obtained new client token: AAAU0NGQFLh+9ATemfQ8m88jR8OhIhpPglKwj65Q9c0ROpJIIqdmGpz3Wr4lt3VvrLehEi2Z+4AqPysw9dwM6aBPEBJ2qmjz7TXRreGrfJD6Iw2+WB9OeiIAMt4RQGLnEyUtgCBwJ4YIr65cIAo+Em+LuSXkJEmKv77zAguzKxN3oTpkahMUzoMsr04nk55myjeDS1NyASO0CElamBjGjWSbTE1n6yR5cvBX4t1GBnMZtULdUhHX9DUNKA==" Feb 19 03:00:08 volumio go-librespot[27263]: time="2026-02-19T03:00:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:09 volumio go-librespot[27263]: time="2026-02-19T03:00:09+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:09 volumio go-librespot[27263]: time="2026-02-19T03:00:09+07:00" level=debug msg="completed challenge" Feb 19 03:00:09 volumio go-librespot[27263]: time="2026-02-19T03:00:09+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 19 03:00:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:09 volumio volumio[27019]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 03:00:09 volumio volumio[27019]: SPOTIFY: BQB_bx7QD53zJkOylp9nDTTZViw0Fi_GH4lJVwIlyOgLW5Ro1h8sy2DVwUjR5o_NnYZJ2WESC3Qri9XglZIaycqiboddTa8YKCGqJWtlCcvBZENChsxRUY-hd2RRz_JTrDiZEDiGJW2jSJhZk9P0CWdwrmyZ6DXuoEkU9qwrFIiFS3VNTeSr9X4MajVJcpffMUVc8q3rXCO6qvWSObUCx0cxkBIpKM52eBZTqu6AuODevFXnHJLyG77_W2GJxEm21mdM6YFjdSMB9QT12fXc2sfV2ZQU2OIKlrhuMO8W8YETfKpWqUveYAPn Feb 19 03:00:09 volumio volumio[27019]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 03:00:09 volumio volumio[27019]: info: New Spotify access token = BQB_bx7QD53zJkOylp9nDTTZViw0Fi_GH4lJVwIlyOgLW5Ro1h8sy2DVwUjR5o_NnYZJ2WESC3Qri9XglZIaycqiboddTa8YKCGqJWtlCcvBZENChsxRUY-hd2RRz_JTrDiZEDiGJW2jSJhZk9P0CWdwrmyZ6DXuoEkU9qwrFIiFS3VNTeSr9X4MajVJcpffMUVc8q3rXCO6qvWSObUCx0cxkBIpKM52eBZTqu6AuODevFXnHJLyG77_W2GJxEm21mdM6YFjdSMB9QT12fXc2sfV2ZQU2OIKlrhuMO8W8YETfKpWqUveYAPn Feb 19 03:00:09 volumio volumio[27019]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 19 03:00:09 volumio volumio[27019]: info: Starting Shairport Sync Feb 19 03:00:09 volumio volumio[27019]: info: Starting Shairport Sync Feb 19 03:00:09 volumio volumio[27019]: info: Starting Shairport Sync Feb 19 03:00:09 volumio sudo[27295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:00:09 volumio sudo[27295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:09 volumio sudo[27297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:00:09 volumio sudo[27297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:09 volumio sudo[27299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:00:09 volumio sudo[27299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:09 volumio volumio[27019]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:09 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 03:00:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 03:00:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:00:09 volumio systemd[1]: shairport-sync.service: Consumed 2.342s CPU time. Feb 19 03:00:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:00:09 volumio sudo[27297]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:09 volumio sudo[27299]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:09 volumio sudo[27295]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:09 volumio volumio[27019]: info: Shairport-Sync Started Feb 19 03:00:09 volumio volumio[27019]: Error adding Membership: Error: addMembership EINVAL Feb 19 03:00:09 volumio volumio[27019]: info: Shairport-Sync Started Feb 19 03:00:09 volumio volumio[27019]: info: Shairport-Sync Started Feb 19 03:00:09 volumio volumio[27019]: 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 19 03:00:09 volumio volumio[27019]: info: Spotify Successfully logged in Feb 19 03:00:09 volumio volumio[27019]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:09 volumio volumio[27019]: info: [1771444809901] CoreMusicLibrary::Adding element Spotify Feb 19 03:00:09 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:09 volumio volumio[27019]: Cannot find translation for source YouTube Music Feb 19 03:00:09 volumio volumio[27019]: Cannot find translation for source Spotify Feb 19 03:00:10 volumio volumio[27019]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 19 03:00:10 volumio volumio[27019]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:00:10 volumio volumio[27019]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:00:10 volumio volumio[27019]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:10 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:10 volumio volumio[27019]: info: CoreStateMachine::pushState Feb 19 03:00:10 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:10 volumio volumio[27019]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:12 volumio volumio[27019]: info: go-librespot daemon successfully initialized Feb 19 03:00:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 19 03:00:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:12 volumio go-librespot[27334]: go-librespot daemon starting... Feb 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00:12+07:00" level=debug msg="app state loaded" Feb 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:12 volumio mpd[27237]: 2026-02-19T03:00:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 19 03:00:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 19 03:00:12 volumio sudo[27197]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:12 volumio sudo[27208]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:12 volumio volumio[27019]: error: MPD error: The expression evaluated to a falsy value: Feb 19 03:00:12 volumio volumio[27019]: assert.ok(self.idling) Feb 19 03:00:12 volumio volumio[27019]: error: The expression evaluated to a falsy value: Feb 19 03:00:12 volumio volumio[27019]: assert.ok(self.idling) Feb 19 03:00:12 volumio volumio[27019]: error: updateQueue error: null Feb 19 03:00:12 volumio volumio[27019]: info: MPD running with PID27237 Feb 19 03:00:12 volumio volumio[27019]: ,establishing connection Feb 19 03:00:12 volumio volumio[27019]: info: Completed starting Core Plugins Feb 19 03:00:12 volumio volumio[27019]: info: ------------------------------------------- Feb 19 03:00:12 volumio volumio[27019]: info: ----- MyVolumio plugins startup ---- Feb 19 03:00:12 volumio volumio[27019]: info: ------------------------------------------- Feb 19 03:00:12 volumio volumio[27019]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 19 03:00:12 volumio volumio[27019]: error: updateQueue error: null Feb 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00:12+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 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00:12+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 19 03:00:12 volumio go-librespot[27335]: time="2026-02-19T03:00:12+07:00" level=info msg="zeroconf server listening on port 38299" Feb 19 03:00:13 volumio go-librespot[27335]: time="2026-02-19T03:00:13+07:00" level=debug msg="obtained new client token: AADbdtECg4Hykp/d7kKM+42FtLSkjPxEWezdzd35pSXXpilbb2RxTzMujit+49riIzGVYh11OXXF1rxEsIyNZrYJFQjb2RFfLTwKWLhJmtXutMoqSFzU7LycAc6JvTDTPKUoqmOzB++MZ2halxhL1//71rp3zA2ztp9wSuFPQdW+5t1SMKF0Ia/fRGMLWL77YL4nHZ5TBrwUmFCm68dWdEs0NFTjqMUdc6HDkKgsB8a6fuAeF5rw7vg=" Feb 19 03:00:13 volumio go-librespot[27335]: time="2026-02-19T03:00:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:13 volumio go-librespot[27335]: time="2026-02-19T03:00:13+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:13 volumio go-librespot[27335]: time="2026-02-19T03:00:13+07:00" level=debug msg="completed challenge" Feb 19 03:00:13 volumio go-librespot[27335]: time="2026-02-19T03:00: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 19 03:00:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:15 volumio volumio[27019]: info: Initializing connection to go-librespot Websocket Feb 19 03:00:15 volumio volumio[27019]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 03:00:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 19 03:00:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:16 volumio go-librespot[27348]: go-librespot daemon starting... Feb 19 03:00:16 volumio go-librespot[27349]: time="2026-02-19T03:00:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:16 volumio go-librespot[27349]: time="2026-02-19T03:00:16+07:00" level=debug msg="app state loaded" Feb 19 03:00:16 volumio go-librespot[27349]: time="2026-02-19T03:00:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00: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 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00: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 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00: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 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00:17+07:00" level=info msg="zeroconf server listening on port 40943" Feb 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00:17+07:00" level=debug msg="obtained new client token: AACzMqvxByhoz073cDsKjMnPdtjr2akKq5f9nItO9BpL0BOpmbXj/uheaENmn+CisI0qBe0JTyrEDB/J8luD+HymAmN7Eg0naoi4UsLmKc4+0u+huBO+tTcwiemYNN7f1+CcLTqgTPMx2Q8sxUkvm5zJfIIZOWhd+SRif/jiG5TTHEq8XXN7zbhpHsNSgVthSlVUoiTKuoVwXd8eii4a3T9Z927n1H/ZdewAf4Y2H18kfBx50W43d5OTMw==" Feb 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:17 volumio volumio[27019]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00:17+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00:17+07:00" level=debug msg="completed challenge" Feb 19 03:00:17 volumio go-librespot[27349]: time="2026-02-19T03:00:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:00:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:18 volumio volumio[27019]: info: Initializing connection to go-librespot Websocket Feb 19 03:00:18 volumio volumio[27019]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 03:00:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 19 03:00:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:20 volumio go-librespot[27357]: go-librespot daemon starting... Feb 19 03:00:20 volumio go-librespot[27358]: time="2026-02-19T03:00:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:20 volumio go-librespot[27358]: time="2026-02-19T03:00:20+07:00" level=debug msg="app state loaded" Feb 19 03:00:20 volumio go-librespot[27358]: time="2026-02-19T03:00:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:21 volumio volumio[27019]: info: Initializing connection to go-librespot Websocket Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=debug msg="new websocket client" Feb 19 03:00:21 volumio volumio[27019]: info: Connection to go-librespot Websocket established Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+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 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+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 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=info msg="zeroconf server listening on port 44213" Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=debug msg="obtained new client token: AABvc1aTALriYWSIcBfwT2b2TRJr3bIgckGTQ8+w/vU8OaKjWHebCvEyR6n9M/WxhiE1XLMhelwX3JvVOv3unNeImxU7mMbPurDTumHlWsRm05UOAo2qcbu+xLXqyTtEOdjoNMTRkGgv28b4LeIebo3ZgkIjc4hYWW946cXESFlbrdlTX4zcLL4yM/9RGnCzOeKHYkGKhx+Ki3yGKmTM+AOZseAFXUNSorwHhVLWrfG0WLLEZ4oP6ovwSQ==" Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin bluetooth to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin multiroom to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin metavolumio to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin cd_controller to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 19 03:00:21 volumio volumio[27019]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+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 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=debug msg="completed challenge" Feb 19 03:00:21 volumio go-librespot[27358]: time="2026-02-19T03:00:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:00:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:23 volumio volumio[27019]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 19 03:00:23 volumio volumio[27019]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 19 03:00:23 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:23 volumio volumio[27019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:23 volumio volumio[27019]: info: Starting MyVolumio Remote Streaming Endpoints Feb 19 03:00:23 volumio volumio[27019]: info: MyVolumio login type: Token Feb 19 03:00:23 volumio volumio[27019]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 19 03:00:23 volumio volumio[27019]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 19 03:00:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 19 03:00:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:25 volumio go-librespot[27380]: go-librespot daemon starting... Feb 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+07:00" level=debug msg="app state loaded" Feb 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:25 volumio volumio[27019]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 19 03:00:25 volumio volumio[27019]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 19 03:00:25 volumio volumio[27019]: info: Streaming services startup Feb 19 03:00:25 volumio volumio[27019]: info: Starting Streaming Daemon Feb 19 03:00:25 volumio sudo[27388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 19 03:00:25 volumio sudo[27388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:25 volumio volumio[27019]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 19 03:00:25 volumio sudo[27388]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:25 volumio volumio[27019]: info: Getting Spotify volume Feb 19 03:00:25 volumio volumio[27019]: info: Connection to go-librespot Websocket closed Feb 19 03:00:25 volumio volumio[27019]: error: Cannot start Volumio Streaming Daemon Feb 19 03:00:25 volumio volumio[27019]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 19 03:00:25 volumio volumio[27019]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 19 03:00:25 volumio volumio[27019]: 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 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+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 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+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 19 03:00:25 volumio go-librespot[27381]: time="2026-02-19T03:00:25+07:00" level=info msg="zeroconf server listening on port 40677" Feb 19 03:00:25 volumio volumio[27019]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:25 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:25 volumio volumio[27019]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 19 03:00:25 volumio volumio[27019]: SPOTIFY: SPOTIFY VOLUME undefined Feb 19 03:00:25 volumio volumio[27019]: SPOTIFY: VOLUMIO VOLUME 100 Feb 19 03:00:25 volumio volumio[27019]: info: Aligning Spotify Volume to Volumio Volume Feb 19 03:00:25 volumio volumio[27019]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:25 volumio volumio[27019]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:25 volumio volumio[27019]: info: Setting Spotify Volume from Volumio: 100 Feb 19 03:00:26 volumio go-librespot[27381]: time="2026-02-19T03:00:26+07:00" level=debug msg="obtained new client token: AAC8CeCCT41NKBQpC9M03ubKUNp/1MZPuozCwoUP7qfkdwltoKz1uLCeEGeVVJ+YIPkwwDTJDDNRHOB3/U+HaMDeMeeUxEKbz55D98yVtRpiccsf3/Ao9NzR7ZamCLLisdPgLxYX9vhuAz1nHMioc54eOA5Yk16Z0tbyMR7bEk1mFP7s3rLfvcbTYwO4GiCR8tLoXPbV/6YCDRiM4iyrD0+YOBuw7lDQSB+g0ZkRb21kHm7daIUPXaU=" Feb 19 03:00:26 volumio go-librespot[27381]: time="2026-02-19T03:00:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:26 volumio go-librespot[27381]: time="2026-02-19T03:00:26+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:26 volumio go-librespot[27381]: time="2026-02-19T03:00:26+07:00" level=debug msg="completed challenge" Feb 19 03:00:26 volumio go-librespot[27381]: time="2026-02-19T03:00:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:00:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:26 volumio volumio[27019]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 03:00:26 volumio volumio[27019]: Error: socket hang up Feb 19 03:00:26 volumio volumio[27019]: at connResetException (node:internal/errors:720:14) Feb 19 03:00:26 volumio volumio[27019]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 19 03:00:26 volumio volumio[27019]: at Socket.emit (node:events:526:35) Feb 19 03:00:26 volumio volumio[27019]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 19 03:00:26 volumio volumio[27019]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 19 03:00:26 volumio volumio[27019]: code: 'ECONNRESET', Feb 19 03:00:26 volumio volumio[27019]: response: undefined Feb 19 03:00:26 volumio volumio[27019]: } Feb 19 03:00:26 volumio volumio[27019]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 03:00:27 volumio sudo[27409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 02:59' Feb 19 03:00:27 volumio sudo[27409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:28 volumio sudo[27409]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:28 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 19 03:00:28 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 19 03:00:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 19 03:00:28 volumio systemd[1]: volumio.service: Consumed 55.551s CPU time. Feb 19 03:00:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 03:00:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 03:00:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22781. Feb 19 03:00:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 03:00:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 19 03:00:28 volumio systemd[1]: volumio.service: Consumed 55.551s CPU time. Feb 19 03:00:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 19 03:00:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 03:00:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 19 03:00:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:29 volumio go-librespot[27436]: go-librespot daemon starting... Feb 19 03:00:29 volumio go-librespot[27437]: time="2026-02-19T03:00:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:29 volumio go-librespot[27437]: time="2026-02-19T03:00:29+07:00" level=debug msg="app state loaded" Feb 19 03:00:29 volumio go-librespot[27437]: time="2026-02-19T03:00:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+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 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+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 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+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 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+07:00" level=info msg="zeroconf server listening on port 46827" Feb 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+07:00" level=debug msg="obtained new client token: AADyPTRinSbBxda2KIPctQu/Y6+YhFGn7Rk4VARkkLsCYUyfZts+Grd5cVpqNH5idML4WbmbP0YC3Y9hiFyI/g+SETJNTDLmbMvXiA4QnZxnaP8msDbEgn21YGCl6PeN6CZ4HOA7cyjySpym/nR9NZ3vlzzD9ZE3gMO+xCXZIWloQHgXTOHlA+XHLRXHDKr0Wy+1+++XuYdeEd0qk+U0nO7Ht4QCF8nVTA9ac5GPfuvuies74B6pSFROMA==" Feb 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+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 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+07:00" level=debug msg="completed challenge" Feb 19 03:00:30 volumio go-librespot[27437]: time="2026-02-19T03:00:30+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 19 03:00:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:32 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:32 volumio volumio[27421]: info: ----- Volumio3 ---- Feb 19 03:00:32 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:32 volumio volumio[27421]: info: ----- System startup ---- Feb 19 03:00:32 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:33 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:33] [connect] Successful connection Feb 19 03:00:33 volumio volumio[27421]: info: MYVOLUMIO Environment detected Feb 19 03:00:33 volumio volumio[27421]: info: Plugin folders cleanup Feb 19 03:00:33 volumio volumio[27421]: info: Scanning into folder /volumio/app/plugins/ Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category audio_interface Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category miscellanea Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category music_service Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category plugins.json Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category system_controller Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category user_interface Feb 19 03:00:33 volumio volumio[27421]: info: Scanning into folder /data/plugins/ Feb 19 03:00:33 volumio volumio[27421]: info: Scanning category music_service Feb 19 03:00:33 volumio volumio[27421]: info: Plugin folders cleanup completed Feb 19 03:00:33 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:33 volumio volumio[27421]: info: ----- Core plugins startup ---- Feb 19 03:00:33 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:33 volumio volumio[27421]: info: Loading plugins from folder /volumio/app/plugins/ Feb 19 03:00:33 volumio volumio[27421]: info: Adding plugin upnp to MyMusic Plugins Feb 19 03:00:33 volumio volumio[27421]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 19 03:00:33 volumio volumio[27421]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 19 03:00:33 volumio volumio[27421]: info: Loading plugins from folder /data/plugins/ Feb 19 03:00:33 volumio volumio[27421]: info: Loading plugin "system"... Feb 19 03:00:33 volumio volumio[27421]: info: Loading plugin "appearance"... Feb 19 03:00:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 19 03:00:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:33 volumio go-librespot[27460]: go-librespot daemon starting... Feb 19 03:00:33 volumio go-librespot[27461]: time="2026-02-19T03:00:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:33 volumio go-librespot[27461]: time="2026-02-19T03:00:33+07:00" level=debug msg="app state loaded" Feb 19 03:00:33 volumio go-librespot[27461]: time="2026-02-19T03:00:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:34 volumio go-librespot[27461]: time="2026-02-19T03:00:34+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 19 03:00:34 volumio go-librespot[27461]: time="2026-02-19T03:00:34+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 19 03:00:34 volumio go-librespot[27461]: time="2026-02-19T03:00:34+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 19 03:00:34 volumio go-librespot[27461]: time="2026-02-19T03:00:34+07:00" level=info msg="zeroconf server listening on port 36885" Feb 19 03:00:34 volumio go-librespot[27461]: time="2026-02-19T03:00:34+07:00" level=debug msg="obtained new client token: AAA37wI140g+DHrH2CzpwC8wdAe7Zw/Tdhq11CtDIqF9uB/zMv7cCTlTRclVVnbvOdBXnzN3VHaKfFS5Wkb9+jUC/ZDx7eQQyz46bhzbskXLffJ/e1TkLthUdqGUku9FsUiZ8iYnOj6GlmMCxuFSBv//3icg73Yl6b1OB2w+3tLSykg5Oex93gCVgJosigWu8N67T1ZbcJR8QWW9dlngWmDD6NisGWHKDvD12D0PyE20DAQg+BPcm4FpiA==" Feb 19 03:00:34 volumio go-librespot[27461]: time="2026-02-19T03:00:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:35 volumio go-librespot[27461]: time="2026-02-19T03:00:35+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:35 volumio go-librespot[27461]: time="2026-02-19T03:00:35+07:00" level=debug msg="completed challenge" Feb 19 03:00:35 volumio go-librespot[27461]: time="2026-02-19T03:00:35+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 19 03:00:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:35 volumio volumio[27421]: info: Loading plugin "network"... Feb 19 03:00:35 volumio volumio[27421]: info: Refreshing Cached IP Addresses Feb 19 03:00:35 volumio sudo[27469]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 03:00:35 volumio sudo[27469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:35 volumio volumio[27421]: info: Loading plugin "services"... Feb 19 03:00:35 volumio sudo[27471]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 03:00:35 volumio sudo[27469]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:35 volumio volumio[27421]: info: Loading plugin "alsa_controller"... Feb 19 03:00:35 volumio sudo[27471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:35 volumio sudo[27471]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:35 volumio sudo[27483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 19 03:00:35 volumio sudo[27483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:35 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:00:35 volumio volumio[27421]: info: Loading plugin "wizard"... Feb 19 03:00:35 volumio volumio[27421]: info: Loading plugin "networkfs"... Feb 19 03:00:36 volumio volumio[27421]: info: Starting Udev Watcher for removable devices Feb 19 03:00:36 volumio volumio[27421]: info: Ignoring mount for partition: boot Feb 19 03:00:36 volumio volumio[27421]: info: Ignoring mount for partition: volumio Feb 19 03:00:36 volumio volumio[27421]: info: Ignoring mount for partition: volumio_data Feb 19 03:00:36 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 03:00:36 volumio volumio[27421]: info: Loading plugin "volumio_command_line_client"... Feb 19 03:00:36 volumio volumio[27421]: info: Loading plugin "upnp"... Feb 19 03:00:36 volumio volumio[27421]: info: [1771444836100] Starting Upmpd Daemon Feb 19 03:00:36 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 03:00:36 volumio volumio[27421]: info: Loading plugin "my_music"... Feb 19 03:00:36 volumio volumio[27421]: info: Loading plugin "mpd"... Feb 19 03:00:36 volumio volumio[27421]: info: Loading plugin "upnp_browser"... Feb 19 03:00:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 19 03:00:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:38 volumio go-librespot[27502]: go-librespot daemon starting... Feb 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+07:00" level=debug msg="app state loaded" Feb 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:38 volumio sudo[27483]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+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 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+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 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+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 19 03:00:38 volumio go-librespot[27503]: time="2026-02-19T03:00:38+07:00" level=info msg="zeroconf server listening on port 37077" Feb 19 03:00:39 volumio go-librespot[27503]: time="2026-02-19T03:00:39+07:00" level=debug msg="obtained new client token: AACnQ4Bq3YustA2dn8sEH3f7dy63LB0S/PNPurQ+sXBP4+yXdYmcCQCj8N9eWi6iUifgHKG+WEz1LQFFgOGITQv8buv631Tr9/j3EDuLjaFekEgTbRap4x+R3VxajvBbTYieN5yyMEI3UeTHi0Nx4sbPYRErtfnyZ4NXeXrdh3YQEUTbYaaXjttFWIaqSHx8wzPRfNtiZBeWmLbjin5V9gxioGQQPA1aVUftWFwk3zAICbxxtYviTAE=" Feb 19 03:00:39 volumio go-librespot[27503]: time="2026-02-19T03:00:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:39 volumio go-librespot[27503]: time="2026-02-19T03:00:39+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:39 volumio go-librespot[27503]: time="2026-02-19T03:00:39+07:00" level=debug msg="completed challenge" Feb 19 03:00:39 volumio go-librespot[27503]: time="2026-02-19T03:00:39+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 19 03:00:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:39 volumio volumio[27421]: info: Starting UPNP Browser Feb 19 03:00:39 volumio volumio[27421]: info: Loading plugin "alarm-clock"... Feb 19 03:00:40 volumio volumio[27421]: info: Loading plugin "airplay_emulation"... Feb 19 03:00:40 volumio volumio[27421]: info: Starting Shairport Sync Feb 19 03:00:40 volumio volumio[27421]: info: Loading plugin "last_100"... Feb 19 03:00:40 volumio volumio[27421]: info: Loading plugin "webradio"... Feb 19 03:00:40 volumio volumio[27421]: info: Loading plugin "i2s_dacs"... Feb 19 03:00:40 volumio volumio[27421]: info: Loading plugin "volumiodiscovery"... Feb 19 03:00:40 volumio volumio[27421]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 03:00:40 volumio node[27421]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 03:00:40 volumio volumio[27421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:00:40 volumio node[27421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:00:40 volumio volumio[27421]: *** WARNING *** For more information see Feb 19 03:00:40 volumio node[27421]: *** WARNING *** For more information see Feb 19 03:00:40 volumio volumio[27421]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 03:00:40 volumio node[27421]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 03:00:40 volumio volumio[27421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:00:40 volumio node[27421]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:00:40 volumio volumio[27421]: *** WARNING *** For more information see Feb 19 03:00:40 volumio node[27421]: *** WARNING *** For more information see Feb 19 03:00:40 volumio volumio[27421]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 19 03:00:40 volumio volumio[27421]: info: Discovery: Started advertising with name: Volumio Feb 19 03:00:40 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 03:00:40 volumio volumio[27421]: info: Loading plugin "spop"... Feb 19 03:00:42 volumio volumio[27421]: info: Loading plugin "ytcr"... Feb 19 03:00:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 19 03:00:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:42 volumio go-librespot[27512]: go-librespot daemon starting... Feb 19 03:00:42 volumio go-librespot[27513]: time="2026-02-19T03:00:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:42 volumio go-librespot[27513]: time="2026-02-19T03:00:42+07:00" level=debug msg="app state loaded" Feb 19 03:00:42 volumio go-librespot[27513]: time="2026-02-19T03:00:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+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 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+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 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+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 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+07:00" level=info msg="zeroconf server listening on port 35905" Feb 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+07:00" level=debug msg="obtained new client token: AABNexhnQB5tk6n/0UpgOkrlIs4bF0U8+4MIeScaWraChKh4xM4KAcmzszDnb+JIKtoM+8eBS+r1IYq5rpdnUpR+n+ej9oL2YRbNyrpaf0+DVv9s/HLo1Jpe6sv993fSdnzLoteijKiokGPsRJ6W9ZCBP8e9Mu7X5yDlAuw8RBWSvEiGUy3CkFqTAkOSjBaAOynRnfoXbfPrQDJGLR6zuDy6rEp7oLiGZ0hAKmdyC5UrLzGySrOwgpiUPQ==" Feb 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00:43+07:00" level=debug msg="completed challenge" Feb 19 03:00:43 volumio go-librespot[27513]: time="2026-02-19T03:00: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 19 03:00:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:44 volumio volumio[27421]: info: Loading plugin "ytmusic"... Feb 19 03:00:45 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:45] [connect] Successful connection Feb 19 03:00:45 volumio volumio[27421]: info: Loading plugin "outputs"... Feb 19 03:00:45 volumio volumio[27421]: info: Loading plugin "albumart"... Feb 19 03:00:46 volumio volumio[27421]: info: Plugin example_plugin is not enabled Feb 19 03:00:46 volumio volumio[27421]: info: Loading plugin "inputs"... Feb 19 03:00:46 volumio volumio[27421]: info: Loading plugin "updater_comm"... Feb 19 03:00:46 volumio volumio[27421]: info: Plugin mpdemulation is not enabled Feb 19 03:00:46 volumio volumio[27421]: info: Loading plugin "rest_api"... Feb 19 03:00:46 volumio volumio[27421]: info: Loading plugin "websocket"... Feb 19 03:00:46 volumio volumio[27421]: info: Starting Socket.io Server version 1.7.4 Feb 19 03:00:46 volumio volumio[27421]: info: Loading plugin "RoonBridge"... Feb 19 03:00:46 volumio volumio[27421]: info: Applying required configuration parameters for plugin RoonBridge Feb 19 03:00:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 19 03:00:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:46 volumio volumio[27421]: info: Loading i18n strings for locale en Feb 19 03:00:46 volumio volumio[27421]: Updating browse sources language Feb 19 03:00:46 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:46 volumio go-librespot[27547]: go-librespot daemon starting... Feb 19 03:00:46 volumio go-librespot[27548]: time="2026-02-19T03:00:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:46 volumio go-librespot[27548]: time="2026-02-19T03:00:46+07:00" level=debug msg="app state loaded" Feb 19 03:00:46 volumio go-librespot[27548]: time="2026-02-19T03:00:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::initPlayerControls Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:00:47 volumio volumio[27537]: Forking 3 albumart workers Feb 19 03:00:47 volumio volumio[27421]: Express server listening on port 3000 Feb 19 03:00:47 volumio volumio[27421]: [Metrics] WebUI: 15s 974.47ms Feb 19 03:00:47 volumio volumio[27421]: info: CoreStateMachine::resetVolumioState Feb 19 03:00:47 volumio volumio[27421]: info: CoreStateMachine::getcurrentVolume Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:00:47 volumio sudo[27581]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 03:00:47 volumio sudo[27581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:47 volumio sudo[27571]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 03:00:47 volumio sudo[27581]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:47 volumio sudo[27571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:47 volumio sudo[27571]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:47 volumio volumio[27421]: info: Volumio Network Manager: Network status updated: 1 Feb 19 03:00:47 volumio go-librespot[27548]: time="2026-02-19T03:00:47+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 19 03:00:47 volumio go-librespot[27548]: time="2026-02-19T03:00:47+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 19 03:00:47 volumio go-librespot[27548]: time="2026-02-19T03:00:47+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 19 03:00:47 volumio go-librespot[27548]: time="2026-02-19T03:00:47+07:00" level=info msg="zeroconf server listening on port 36967" Feb 19 03:00:47 volumio go-librespot[27548]: time="2026-02-19T03:00:47+07:00" level=debug msg="obtained new client token: AABpMgZpz4PIRxJ1UifTUmrUbQUPgOd3P01aN39zC8ow6qAxk5UDSVCk8ceYgkg8qDbd4f0vbsFHOAwlRgBS3LF40lrbfLCUZx7o9wdPMxB4umyXM+0H2NA1rmbg+QYKf13BWBnUC4d23p8XwmsYx2eHknfgySxgvxSzPya8C9Ds/jCYLcQmyEEGKeqtvVFs+/LQllB1msycUk3xTtrhIc+JwDZdtsBnFoSB27R57fqDYczv11Le/Hr+xA==" Feb 19 03:00:47 volumio volumio[27421]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:00:47 volumio volumio[27421]: info: CoreStateMachine::pushState Feb 19 03:00:47 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 03:00:47 volumio go-librespot[27548]: time="2026-02-19T03:00:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:47 volumio volumio[27421]: info: CoreStateMachine::updateTrackBlock Feb 19 03:00:47 volumio volumio[27421]: info: CorePlayQueue::getTrackBlock Feb 19 03:00:47 volumio volumio[27421]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:00:48 volumio volumio-remote-updater[25144]: [2026-02-19 03:00:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771444845 101 Feb 19 03:00:48 volumio go-librespot[27548]: time="2026-02-19T03:00:48+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:48 volumio go-librespot[27548]: time="2026-02-19T03:00:48+07:00" level=debug msg="completed challenge" Feb 19 03:00:48 volumio volumio[27421]: 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 19 03:00:48 volumio go-librespot[27548]: time="2026-02-19T03:00:48+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 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:48 volumio volumio[27421]: info: Reloading queue from file Feb 19 03:00:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:48 volumio volumio[27421]: info: CoreStateMachine::setRepeat null single undefined Feb 19 03:00:48 volumio volumio[27421]: info: CoreStateMachine::pushState Feb 19 03:00:48 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:48 volumio volumio[27421]: info: CoreStateMachine::setRandom null Feb 19 03:00:48 volumio volumio[27421]: info: CoreStateMachine::pushState Feb 19 03:00:48 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:48 volumio volumio[27421]: info: Setting Device type: Raspberry PI Feb 19 03:00:48 volumio volumio[27421]: info: Completed loading Core Plugins Feb 19 03:00:48 volumio volumio[27421]: info: Preparing to generate the ALSA configuration file Feb 19 03:00:48 volumio volumio[27421]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:00:48 volumio volumio[27421]: info: CoreStateMachine::pushState Feb 19 03:00:48 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:48 volumio volumio[27421]: info: Asound.conf file unchanged, so no further update is needed Feb 19 03:00:48 volumio volumio[27421]: info: Output device has changed, restarting MPD Feb 19 03:00:48 volumio volumio[27421]: info: Output device has changed, restarting Shairport Sync Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:48 volumio sudo[27606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 19 03:00:48 volumio sudo[27606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:48 volumio sudo[27608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 03:00:48 volumio sudo[27608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:48 volumio sudo[27608]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:48 volumio sudo[27610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 03:00:48 volumio sudo[27610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:48 volumio volumio[27421]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:00:48 volumio volumio[27421]: info: ___________ START PLUGINS ___________ Feb 19 03:00:48 volumio sudo[27606]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:48 volumio volumio[27421]: info: ControllerMpd::onStart: Initializing MPD Feb 19 03:00:48 volumio volumio[27421]: info: Creating MPD Configuration file Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:48 volumio volumio[27421]: info: [1771444848664] CoreMusicLibrary::Adding element Media Servers Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 19 03:00:48 volumio sudo[27619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 03:00:48 volumio sudo[27619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:48 volumio sudo[27619]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:48 volumio sudo[27621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 03:00:48 volumio volumio[27421]: info: UPNP Browser: Client initialized successfully Feb 19 03:00:48 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 03:00:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 03:00:48 volumio systemd[1]: mpd.service: Consumed 7.272s CPU time. Feb 19 03:00:48 volumio sudo[27621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 03:00:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 03:00:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 03:00:48 volumio volumio[27421]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:00:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:48 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:49 volumio volumio[27421]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:00:49 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 03:00:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:49 volumio volumio[27421]: info: [1771444849013] CoreMusicLibrary::Adding element Last_100 Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 03:00:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 03:00:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:49 volumio volumio[27421]: info: [1771444849026] CoreMusicLibrary::Adding element Webradio Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:00:49 volumio volumio[27421]: info: Initializing BBC Radios Feb 19 03:00:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 03:00:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:49 volumio volumio[27421]: info: Creating Spotify config file Feb 19 03:00:49 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:49 volumio sudo[27638]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 19 03:00:49 volumio sudo[27638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 19 03:00:49 volumio sudo[27638]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:50 volumio volumio[27559]: Starting albumart workers Feb 19 03:00:50 volumio volumio[27421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:50 volumio volumio[27421]: info: [1771444850577] CoreMusicLibrary::Adding element YouTube Music Feb 19 03:00:50 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:50 volumio volumio[27421]: Cannot find translation for source YouTube Music Feb 19 03:00:50 volumio volumio[27556]: Starting albumart workers Feb 19 03:00:50 volumio volumio[27560]: Starting albumart workers Feb 19 03:00:50 volumio volumio[27421]: info: Volumio Calling Home Feb 19 03:00:50 volumio sudo[27652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 19 03:00:50 volumio sudo[27652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:50 volumio sudo[27652]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 19 03:00:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:51 volumio go-librespot[27657]: go-librespot daemon starting... Feb 19 03:00:51 volumio go-librespot[27658]: time="2026-02-19T03:00:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:51 volumio volumio[27421]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 03:00:51 volumio volumio[27421]: info: Discovery: Found device Volumio Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:51 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:51 volumio volumio[27421]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 03:00:51 volumio volumio[27421]: info: Discovery: Found device Volumio Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:51 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:51 volumio volumio[27421]: info: MPD Permissions set Feb 19 03:00:51 volumio volumio[27421]: info: MPD Permissions set Feb 19 03:00:51 volumio volumio[27421]: info: Upmpdcli Daemon Started Feb 19 03:00:51 volumio volumio[27421]: info: Spotify config file written Feb 19 03:00:51 volumio volumio[27421]: 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 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio sudo[27665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 19 03:00:51 volumio sudo[27665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:51 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 19 03:00:52 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 19 03:00:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:00:52 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:00:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:52 volumio volumio[27421]: info: No need to fix Spotify hosts Feb 19 03:00:52 volumio go-librespot[27674]: go-librespot daemon starting... Feb 19 03:00:52 volumio sudo[27665]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:52 volumio go-librespot[27680]: time="2026-02-19T03:00:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:52 volumio go-librespot[27680]: time="2026-02-19T03:00:52+07:00" level=debug msg="app state loaded" Feb 19 03:00:52 volumio go-librespot[27680]: time="2026-02-19T03:00:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+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 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+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 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+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 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+07:00" level=info msg="zeroconf server listening on port 40703" Feb 19 03:00:53 volumio volumio[27421]: info: Volumio called home Feb 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+07:00" level=debug msg="obtained new client token: AADaz6oM4gnTPeQa6pXDQjzR+FTpDSKn7gQD8fP3NRHN5QZwzSHcuvhb1o+wxQVCAv3LpkfZzo+wapHMX3a8AlkekvoT78EkZ4WTtLTTbmT7RyblLWc35taxSRqkOByFxEkFyPtpLAXf5KbzS3NVW0Wm5m4uYNy6WeJa4yoJfGIWjJdZGzg7PCfFsOptpJGUMqQLfyGUUDS5leKew3P5fjT5At/Yg3T9grsXSPfhN3Vtl2eDXCmwm0A=" Feb 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+07:00" level=debug msg="completed challenge" Feb 19 03:00:53 volumio volumio[27421]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 03:00:53 volumio volumio[27421]: SPOTIFY: BQBou63IIIRO_LEr4Cw33Sn2rY9uYuPxu1EqjYWtqPL-hk_FHY6LTgCswhe2EZ1nEnUC7mMtn7b8-R6jlZHKWwBFgEKETEvGiLF4cT5ajeeMLdUzWWFN0GrJKt4OFlMjPMuAXKC5vqsIhiLbcnaLn982GdlclNuLBF0eJA3IKv9k_sWMLXD5mJ-8w0_3RKTAh4VSOa---TN_cCjiznak7CiaPPUhVEMmr7-J_JrRH7t2aaWPlEU05RaHW5MVNQwhShkZG991-KhCstkUTdgK5IJyJWXbD2ebdlcgp1Sl-YUqjVezl1Gutbbx Feb 19 03:00:53 volumio volumio[27421]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 03:00:53 volumio volumio[27421]: info: New Spotify access token = BQBou63IIIRO_LEr4Cw33Sn2rY9uYuPxu1EqjYWtqPL-hk_FHY6LTgCswhe2EZ1nEnUC7mMtn7b8-R6jlZHKWwBFgEKETEvGiLF4cT5ajeeMLdUzWWFN0GrJKt4OFlMjPMuAXKC5vqsIhiLbcnaLn982GdlclNuLBF0eJA3IKv9k_sWMLXD5mJ-8w0_3RKTAh4VSOa---TN_cCjiznak7CiaPPUhVEMmr7-J_JrRH7t2aaWPlEU05RaHW5MVNQwhShkZG991-KhCstkUTdgK5IJyJWXbD2ebdlcgp1Sl-YUqjVezl1Gutbbx Feb 19 03:00:53 volumio volumio[27421]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 19 03:00:53 volumio go-librespot[27680]: time="2026-02-19T03:00:53+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 19 03:00:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:53 volumio volumio[27421]: info: Starting Shairport Sync Feb 19 03:00:53 volumio volumio[27421]: info: Starting Shairport Sync Feb 19 03:00:53 volumio volumio[27421]: info: Starting Shairport Sync Feb 19 03:00:53 volumio sudo[27707]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:00:53 volumio sudo[27707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:53 volumio sudo[27709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:00:53 volumio sudo[27709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:53 volumio sudo[27711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:00:53 volumio sudo[27711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:00:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 03:00:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 03:00:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:00:53 volumio systemd[1]: shairport-sync.service: Consumed 2.305s CPU time. Feb 19 03:00:53 volumio volumio[27421]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:53 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:00:54 volumio sudo[27707]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:54 volumio sudo[27709]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 03:00:54 volumio volumio[27421]: info: Shairport-Sync Started Feb 19 03:00:54 volumio volumio[27421]: Error adding Membership: Error: addMembership EINVAL Feb 19 03:00:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 03:00:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:00:54 volumio volumio[27421]: info: Shairport-Sync Started Feb 19 03:00:54 volumio volumio[27421]: 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 19 03:00:54 volumio volumio[27421]: info: Spotify Successfully logged in Feb 19 03:00:54 volumio volumio[27421]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:00:54 volumio volumio[27421]: info: [1771444854229] CoreMusicLibrary::Adding element Spotify Feb 19 03:00:54 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:00:54 volumio volumio[27421]: Cannot find translation for source YouTube Music Feb 19 03:00:54 volumio volumio[27421]: Cannot find translation for source Spotify Feb 19 03:00:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:00:54 volumio sudo[27711]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:54 volumio volumio[27421]: info: Shairport-Sync Started Feb 19 03:00:54 volumio volumio[27421]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 19 03:00:55 volumio volumio[27421]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:00:55 volumio volumio[27421]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:00:55 volumio volumio[27421]: info: CoreCommandRouter::volumioGetState Feb 19 03:00:55 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:55 volumio volumio[27421]: info: CoreStateMachine::pushState Feb 19 03:00:55 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:00:55 volumio volumio[27421]: info: CoreCommandRouter::volumioPushState Feb 19 03:00:56 volumio volumio[27421]: info: go-librespot daemon successfully initialized Feb 19 03:00:56 volumio mpd[27650]: 2026-02-19T03:00:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 19 03:00:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 19 03:00:56 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 19 03:00:56 volumio sudo[27621]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:56 volumio sudo[27610]: pam_unix(sudo:session): session closed for user root Feb 19 03:00:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:00:56 volumio go-librespot[27752]: go-librespot daemon starting... Feb 19 03:00:56 volumio go-librespot[27753]: time="2026-02-19T03:00:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:00:56 volumio go-librespot[27753]: time="2026-02-19T03:00:56+07:00" level=debug msg="app state loaded" Feb 19 03:00:56 volumio go-librespot[27753]: time="2026-02-19T03:00:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:00:56 volumio volumio[27421]: error: MPD error: The expression evaluated to a falsy value: Feb 19 03:00:56 volumio volumio[27421]: assert.ok(self.idling) Feb 19 03:00:56 volumio volumio[27421]: error: The expression evaluated to a falsy value: Feb 19 03:00:56 volumio volumio[27421]: assert.ok(self.idling) Feb 19 03:00:56 volumio volumio[27421]: info: MPD running with PID27650 Feb 19 03:00:56 volumio volumio[27421]: ,establishing connection Feb 19 03:00:56 volumio volumio[27421]: error: updateQueue error: null Feb 19 03:00:57 volumio volumio[27421]: info: Completed starting Core Plugins Feb 19 03:00:57 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:57 volumio volumio[27421]: info: ----- MyVolumio plugins startup ---- Feb 19 03:00:57 volumio volumio[27421]: info: ------------------------------------------- Feb 19 03:00:57 volumio volumio[27421]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 19 03:00:57 volumio volumio[27421]: error: updateQueue error: null Feb 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+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 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+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 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+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 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+07:00" level=info msg="zeroconf server listening on port 38227" Feb 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+07:00" level=debug msg="obtained new client token: AAAUxLW5bDgrrcrLNtGM5h9aRWP1ec9e6b6EnNzTT2m0yOs/j3lh5zl2F6OO5r7yRP8XWAoYhjtRqfme1yRfBcnKw2JvmLNn5SZbGS2OdFSK6Yv7qZQkl82UgESbNDKfT+gDen7iwmD9WewXYyG4RzahkDiYuS7LGW5uObZq6sp7+rN0rIeDU+FA7L003pneBVkQ+jXaYwnWPmd8n/M0pJMpHtelcyn2pECY7KTXFZzBbr6r1xBJ5dhmyA==" Feb 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+07:00" level=debug msg="completed keyexchange" Feb 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+07:00" level=debug msg="completed challenge" Feb 19 03:00:57 volumio go-librespot[27753]: time="2026-02-19T03:00:57+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 19 03:00:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:00:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:00:59 volumio volumio[27421]: info: Initializing connection to go-librespot Websocket Feb 19 03:00:59 volumio volumio[27421]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 03:01:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 19 03:01:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:01 volumio go-librespot[27760]: go-librespot daemon starting... Feb 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+07:00" level=debug msg="app state loaded" Feb 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+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 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+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 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+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 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+07:00" level=info msg="zeroconf server listening on port 37463" Feb 19 03:01:01 volumio volumio[27421]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 19 03:01:01 volumio go-librespot[27761]: time="2026-02-19T03:01:01+07:00" level=debug msg="obtained new client token: AAClQrn6VlT8k/qlPaCXFMoqlepcQVNzH0m2tKn/vMkLg+4YDOW4sfhxt8biE9ZDibrVtUFUcEVeRJY5zUdH0Hg8WXVhvTkXlp7THg8IzBW4MgN1sLtIBJ2nIVqvsf8L7y4ThEHMIukS/MQJacyLdoQbibcWk0CXs40otYFgI6apZI4BrqpNRGnl4Mrz9D2473MRwL4MtIUiK0o8xpDZRce+fCTLcLufo/iSU2+1SjyDy3iDHoGE3BVrWA==" Feb 19 03:01:02 volumio go-librespot[27761]: time="2026-02-19T03:01:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:02 volumio go-librespot[27761]: time="2026-02-19T03:01:02+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:02 volumio go-librespot[27761]: time="2026-02-19T03:01:02+07:00" level=debug msg="completed challenge" Feb 19 03:01:02 volumio go-librespot[27761]: time="2026-02-19T03:01:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:01:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:02 volumio volumio[27421]: info: Initializing connection to go-librespot Websocket Feb 19 03:01:02 volumio volumio[27421]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 03:01:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 19 03:01:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:05 volumio go-librespot[27770]: go-librespot daemon starting... Feb 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+07:00" level=debug msg="app state loaded" Feb 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:05 volumio volumio[27421]: info: Initializing connection to go-librespot Websocket Feb 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+07:00" level=debug msg="new websocket client" Feb 19 03:01:05 volumio volumio[27421]: info: Connection to go-librespot Websocket established Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin bluetooth to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin multiroom to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin metavolumio to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin cd_controller to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 19 03:01:05 volumio volumio[27421]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+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 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+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 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+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 19 03:01:05 volumio go-librespot[27771]: time="2026-02-19T03:01:05+07:00" level=info msg="zeroconf server listening on port 35321" Feb 19 03:01:06 volumio go-librespot[27771]: time="2026-02-19T03:01:06+07:00" level=debug msg="obtained new client token: AAC3SSD82nwwsmSDbDBME0QSyf0nhGa3EDmErKPoME92yHnEK/Or0qKFLPT9DUcKLJqFn6tCfOKf+G+rTA95OALLPPVNBH+93/Y+bqfOOzsy8YK91jkrA8AL5PO/mjNIgXlIFw+TQN8bWluxZTRRsE7g2pg2B/zBnXMYklkRlQzKT/zn7r9qov12zL3jk/6gk8OXsygtomBXbQy3rP5dox0SNf8Jjp1j1MI7073YMEHIWTMUXlLBUck=" Feb 19 03:01:06 volumio go-librespot[27771]: time="2026-02-19T03:01:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:06 volumio go-librespot[27771]: time="2026-02-19T03:01:06+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:06 volumio go-librespot[27771]: time="2026-02-19T03:01:06+07:00" level=debug msg="completed challenge" Feb 19 03:01:06 volumio go-librespot[27771]: time="2026-02-19T03:01:06+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 19 03:01:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:07 volumio volumio[27421]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 19 03:01:07 volumio volumio[27421]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 19 03:01:07 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:07 volumio volumio[27421]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:07 volumio volumio[27421]: info: Starting MyVolumio Remote Streaming Endpoints Feb 19 03:01:07 volumio volumio[27421]: info: MyVolumio login type: Token Feb 19 03:01:07 volumio volumio[27421]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 19 03:01:07 volumio volumio[27421]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 19 03:01:09 volumio volumio[27421]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 19 03:01:09 volumio volumio[27421]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 19 03:01:09 volumio volumio[27421]: info: Streaming services startup Feb 19 03:01:09 volumio volumio[27421]: info: Starting Streaming Daemon Feb 19 03:01:09 volumio sudo[27793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 19 03:01:09 volumio sudo[27793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:09 volumio volumio[27421]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 19 03:01:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 19 03:01:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:09 volumio go-librespot[27799]: go-librespot daemon starting... Feb 19 03:01:09 volumio sudo[27793]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:09 volumio go-librespot[27800]: time="2026-02-19T03:01:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:09 volumio volumio[27421]: info: Getting Spotify volume Feb 19 03:01:09 volumio go-librespot[27800]: time="2026-02-19T03:01:09+07:00" level=debug msg="app state loaded" Feb 19 03:01:09 volumio go-librespot[27800]: time="2026-02-19T03:01:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:09 volumio volumio[27421]: info: Connection to go-librespot Websocket closed Feb 19 03:01:09 volumio volumio[27421]: error: Cannot start Volumio Streaming Daemon Feb 19 03:01:09 volumio volumio[27421]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 19 03:01:09 volumio volumio[27421]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 19 03:01:09 volumio volumio[27421]: 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 19 03:01:10 volumio volumio[27421]: info: CoreCommandRouter::volumioGetState Feb 19 03:01:10 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:10 volumio volumio[27421]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 19 03:01:10 volumio volumio[27421]: SPOTIFY: SPOTIFY VOLUME undefined Feb 19 03:01:10 volumio volumio[27421]: SPOTIFY: VOLUMIO VOLUME 100 Feb 19 03:01:10 volumio volumio[27421]: info: Aligning Spotify Volume to Volumio Volume Feb 19 03:01:10 volumio volumio[27421]: info: CoreCommandRouter::volumioGetState Feb 19 03:01:10 volumio volumio[27421]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:10 volumio volumio[27421]: info: Setting Spotify Volume from Volumio: 100 Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+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 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+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 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+07:00" level=info msg="zeroconf server listening on port 36305" Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+07:00" level=debug msg="obtained new client token: AAC0BY/3YJQ66pCDD9FtKeajEN6K3ttnV2dH+SIJ5o1knEstgrqzLz8kW7B9f4lZF+iOPG1Atf25ifOFlcx32SuHqNHgZECy3npKC2tueKjSpYwoDGLWW3fXD42HaOelwlQmhoWG5ZnZ9s4sr12OcRGmZkBbNq0O0aWqlByhi63rrkxSSsRPOfo9h6V7zxIQ+ecnYXaZ9nrhWkGUMexh2mmowtdpxxvD9nbzbC7QHrBIPBWNg/FDW7Bn4g==" Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:10 volumio volumio[27421]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+07:00" level=debug msg="completed challenge" Feb 19 03:01:10 volumio go-librespot[27800]: time="2026-02-19T03:01:10+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 19 03:01:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:10 volumio volumio[27421]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 03:01:10 volumio volumio[27421]: Error: socket hang up Feb 19 03:01:10 volumio volumio[27421]: at connResetException (node:internal/errors:720:14) Feb 19 03:01:10 volumio volumio[27421]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 19 03:01:10 volumio volumio[27421]: at Socket.emit (node:events:526:35) Feb 19 03:01:10 volumio volumio[27421]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 19 03:01:10 volumio volumio[27421]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 19 03:01:10 volumio volumio[27421]: code: 'ECONNRESET', Feb 19 03:01:10 volumio volumio[27421]: response: undefined Feb 19 03:01:10 volumio volumio[27421]: } Feb 19 03:01:10 volumio volumio[27421]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 03:01:12 volumio sudo[27822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 03:00' Feb 19 03:01:12 volumio sudo[27822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:12 volumio sudo[27822]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:12 volumio volumio-remote-updater[25144]: [2026-02-19 03:01:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 19 03:01:12 volumio volumio-remote-updater[25144]: [2026-02-19 03:01:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 19 03:01:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 19 03:01:12 volumio systemd[1]: volumio.service: Consumed 55.784s CPU time. Feb 19 03:01:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 03:01:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 03:01:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22782. Feb 19 03:01:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 19 03:01:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 19 03:01:12 volumio systemd[1]: volumio.service: Consumed 55.784s CPU time. Feb 19 03:01:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 19 03:01:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 19 03:01:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 19 03:01:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:14 volumio go-librespot[27851]: go-librespot daemon starting... Feb 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+07:00" level=debug msg="app state loaded" Feb 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+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 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+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 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+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 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+07:00" level=info msg="zeroconf server listening on port 36541" Feb 19 03:01:14 volumio go-librespot[27852]: time="2026-02-19T03:01:14+07:00" level=debug msg="obtained new client token: AAAEGwK2OjTMxDYXU54o7EjW2o2vgHGxweEMAEjv8+8pFhzjkjuznyY/XsKCSs/F2RbG+u9Dh2zzz4wOJo+3yh3A8eZ2Ag+/WJ6yj32oI9kmqITaqpmrXyuNwmybE7Tt9zHpGg6GUqw3yP4H16STZEtyT/uBnkeq3B4QgFTelK1eW5Xu1ePNDxaFLmy3Xx+nBSlZlblBABPfrvj7yOAdKWNrJn+3j1g9Bp/8IOAPBwMmLU2RkxSzX05+GQ==" Feb 19 03:01:15 volumio go-librespot[27852]: time="2026-02-19T03:01:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:15 volumio go-librespot[27852]: time="2026-02-19T03:01:15+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:15 volumio go-librespot[27852]: time="2026-02-19T03:01:15+07:00" level=debug msg="completed challenge" Feb 19 03:01:15 volumio go-librespot[27852]: time="2026-02-19T03:01: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 19 03:01:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:16 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:16 volumio volumio[27834]: info: ----- Volumio3 ---- Feb 19 03:01:16 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:16 volumio volumio[27834]: info: ----- System startup ---- Feb 19 03:01:16 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:17 volumio volumio-remote-updater[25144]: [2026-02-19 03:01:17] [connect] Successful connection Feb 19 03:01:17 volumio volumio[27834]: info: MYVOLUMIO Environment detected Feb 19 03:01:18 volumio volumio[27834]: info: Plugin folders cleanup Feb 19 03:01:18 volumio volumio[27834]: info: Scanning into folder /volumio/app/plugins/ Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category audio_interface Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category miscellanea Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category music_service Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category plugins.json Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category system_controller Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category user_interface Feb 19 03:01:18 volumio volumio[27834]: info: Scanning into folder /data/plugins/ Feb 19 03:01:18 volumio volumio[27834]: info: Scanning category music_service Feb 19 03:01:18 volumio volumio[27834]: info: Plugin folders cleanup completed Feb 19 03:01:18 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:18 volumio volumio[27834]: info: ----- Core plugins startup ---- Feb 19 03:01:18 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:18 volumio volumio[27834]: info: Loading plugins from folder /volumio/app/plugins/ Feb 19 03:01:18 volumio volumio[27834]: info: Adding plugin upnp to MyMusic Plugins Feb 19 03:01:18 volumio volumio[27834]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 19 03:01:18 volumio volumio[27834]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 19 03:01:18 volumio volumio[27834]: info: Loading plugins from folder /data/plugins/ Feb 19 03:01:18 volumio volumio[27834]: info: Loading plugin "system"... Feb 19 03:01:18 volumio volumio[27834]: info: Loading plugin "appearance"... Feb 19 03:01:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 19 03:01:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:18 volumio go-librespot[27872]: go-librespot daemon starting... Feb 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+07:00" level=debug msg="app state loaded" Feb 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+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 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+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 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+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 19 03:01:18 volumio go-librespot[27873]: time="2026-02-19T03:01:18+07:00" level=info msg="zeroconf server listening on port 35861" Feb 19 03:01:19 volumio go-librespot[27873]: time="2026-02-19T03:01:19+07:00" level=debug msg="obtained new client token: AACUIZgVrDmSQM1BiXA9K8yPdwYJ8cQmt4/3PPbj2687ZK7+qRr4+SXwzAhDIgnBNc//+l3FaSOQmDczUrrwKc5LrmGycfnThDXlzBYo1O1nfMuqjKhF7ALkeb8MqShreefynUlClM14PncwwH3ct+qJ3Qo6Qc4pjDni2Wy0+PFpn3mRm2iaHj/u/IQPvI2sEOjfGeZlpoo2vvIe+jjRssZY8P4p9A2WWmU3mL7oOWrNSHmoZjUMS70=" Feb 19 03:01:19 volumio go-librespot[27873]: time="2026-02-19T03:01:19+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 19 03:01:19 volumio go-librespot[27873]: time="2026-02-19T03:01:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 19 03:01:19 volumio go-librespot[27873]: time="2026-02-19T03:01:19+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:19 volumio go-librespot[27873]: time="2026-02-19T03:01:19+07:00" level=debug msg="completed challenge" Feb 19 03:01:19 volumio go-librespot[27873]: time="2026-02-19T03:01:19+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 19 03:01:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "network"... Feb 19 03:01:20 volumio volumio[27834]: info: Refreshing Cached IP Addresses Feb 19 03:01:20 volumio sudo[27881]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 03:01:20 volumio sudo[27881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:20 volumio sudo[27883]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 03:01:20 volumio sudo[27883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "services"... Feb 19 03:01:20 volumio sudo[27883]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:20 volumio sudo[27881]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "alsa_controller"... Feb 19 03:01:20 volumio sudo[27891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 19 03:01:20 volumio sudo[27891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:20 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "wizard"... Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "networkfs"... Feb 19 03:01:20 volumio volumio[27834]: info: Starting Udev Watcher for removable devices Feb 19 03:01:20 volumio volumio[27834]: info: Ignoring mount for partition: boot Feb 19 03:01:20 volumio volumio[27834]: info: Ignoring mount for partition: volumio Feb 19 03:01:20 volumio volumio[27834]: info: Ignoring mount for partition: volumio_data Feb 19 03:01:20 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "volumio_command_line_client"... Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "upnp"... Feb 19 03:01:20 volumio volumio[27834]: info: [1771444880527] Starting Upmpd Daemon Feb 19 03:01:20 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "my_music"... Feb 19 03:01:20 volumio volumio[27834]: info: Loading plugin "mpd"... Feb 19 03:01:21 volumio volumio[27834]: info: Loading plugin "upnp_browser"... Feb 19 03:01:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 19 03:01:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:22 volumio go-librespot[27914]: go-librespot daemon starting... Feb 19 03:01:22 volumio go-librespot[27915]: time="2026-02-19T03:01:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:22 volumio go-librespot[27915]: time="2026-02-19T03:01:22+07:00" level=debug msg="app state loaded" Feb 19 03:01:22 volumio go-librespot[27915]: time="2026-02-19T03:01:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:22 volumio sudo[27891]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01: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 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01: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 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01: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 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01:23+07:00" level=info msg="zeroconf server listening on port 34701" Feb 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01:23+07:00" level=debug msg="obtained new client token: AACy9bnymsKMqyzegJatKBV3awQekA4iTaEdll1FBUSb5pZ3WG+PlGrtvDh8l8UzgA64Wdv3K6UCwcV/lQuJenXvhVAlpLnR+ESa91CZT1bthe43nXePa7mB+F9BVIhYb3hbEoqqzgreXWg7wSKnPgOJwUJJ1Y/gI1lQDXI8rjCNwwudZQolLIh+UQOUgVAwoaaFZ/u2xZ6Y6FY02rZnyxBoszr6eccHRwFniI4GM7oEbzAOl778XCMsqw==" Feb 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01:23+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 19 03:01:23 volumio go-librespot[27915]: time="2026-02-19T03:01:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 19 03:01:24 volumio volumio[27834]: info: Starting UPNP Browser Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "alarm-clock"... Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "airplay_emulation"... Feb 19 03:01:24 volumio volumio[27834]: info: Starting Shairport Sync Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "last_100"... Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "webradio"... Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "i2s_dacs"... Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "volumiodiscovery"... Feb 19 03:01:24 volumio volumio[27834]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 03:01:24 volumio volumio[27834]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:01:24 volumio node[27834]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 19 03:01:24 volumio volumio[27834]: *** WARNING *** For more information see Feb 19 03:01:24 volumio volumio[27834]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 03:01:24 volumio volumio[27834]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:01:24 volumio volumio[27834]: *** WARNING *** For more information see Feb 19 03:01:24 volumio node[27834]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:01:24 volumio node[27834]: *** WARNING *** For more information see Feb 19 03:01:24 volumio node[27834]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 19 03:01:24 volumio node[27834]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 19 03:01:24 volumio node[27834]: *** WARNING *** For more information see Feb 19 03:01:24 volumio volumio[27834]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 19 03:01:24 volumio volumio[27834]: info: Discovery: Started advertising with name: Volumio Feb 19 03:01:24 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 19 03:01:24 volumio volumio[27834]: info: Loading plugin "spop"... Feb 19 03:01:26 volumio volumio[27834]: info: Loading plugin "ytcr"... Feb 19 03:01:29 volumio volumio[27834]: info: Loading plugin "ytmusic"... Feb 19 03:01:30 volumio volumio-remote-updater[25144]: [2026-02-19 03:01:30] [connect] Successful connection Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "outputs"... Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "albumart"... Feb 19 03:01:30 volumio volumio[27834]: info: Plugin example_plugin is not enabled Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "inputs"... Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "updater_comm"... Feb 19 03:01:30 volumio volumio[27834]: info: Plugin mpdemulation is not enabled Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "rest_api"... Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "websocket"... Feb 19 03:01:30 volumio volumio[27834]: info: Starting Socket.io Server version 1.7.4 Feb 19 03:01:30 volumio volumio[27834]: info: Loading plugin "RoonBridge"... Feb 19 03:01:31 volumio volumio[27834]: info: Applying required configuration parameters for plugin RoonBridge Feb 19 03:01:31 volumio volumio[27834]: info: Loading i18n strings for locale en Feb 19 03:01:31 volumio volumio[27834]: Updating browse sources language Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:01:31 volumio volumio[27928]: Forking 3 albumart workers Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::initPlayerControls Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:01:31 volumio volumio[27834]: Express server listening on port 3000 Feb 19 03:01:31 volumio volumio[27834]: [Metrics] WebUI: 15s 895.80ms Feb 19 03:01:31 volumio volumio[27834]: info: CoreStateMachine::resetVolumioState Feb 19 03:01:31 volumio volumio[27834]: info: CoreStateMachine::getcurrentVolume Feb 19 03:01:31 volumio volumio[27834]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:01:31 volumio sudo[27984]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 19 03:01:31 volumio sudo[27984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:31 volumio volumio[27834]: info: Volumio Network Manager: Network status updated: 1 Feb 19 03:01:31 volumio sudo[27984]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:31 volumio sudo[27985]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 19 03:01:31 volumio sudo[27985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:31 volumio sudo[27985]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:32 volumio volumio[27834]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::pushState Feb 19 03:01:32 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::volumioPushState Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::updateTrackBlock Feb 19 03:01:32 volumio volumio[27834]: info: CorePlayQueue::getTrackBlock Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:01:32 volumio volumio-remote-updater[25144]: [2026-02-19 03:01:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771444890 101 Feb 19 03:01:32 volumio volumio[27834]: 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 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:32 volumio volumio[27834]: info: Reloading queue from file Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::setRepeat null single undefined Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::pushState Feb 19 03:01:32 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::volumioPushState Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::setRandom null Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::pushState Feb 19 03:01:32 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::volumioPushState Feb 19 03:01:32 volumio volumio[27834]: info: Setting Device type: Raspberry PI Feb 19 03:01:32 volumio volumio[27834]: info: Completed loading Core Plugins Feb 19 03:01:32 volumio volumio[27834]: info: Preparing to generate the ALSA configuration file Feb 19 03:01:32 volumio volumio[27834]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:01:32 volumio volumio[27834]: info: CoreStateMachine::pushState Feb 19 03:01:32 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::volumioPushState Feb 19 03:01:32 volumio volumio[27834]: info: Asound.conf file unchanged, so no further update is needed Feb 19 03:01:32 volumio volumio[27834]: info: Output device has changed, restarting MPD Feb 19 03:01:32 volumio volumio[27834]: info: Output device has changed, restarting Shairport Sync Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:32 volumio sudo[28002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 19 03:01:32 volumio sudo[28002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:32 volumio sudo[28004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 03:01:32 volumio sudo[28004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:32 volumio sudo[28004]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:32 volumio sudo[28006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 03:01:32 volumio sudo[28006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:32 volumio volumio[27834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:01:32 volumio volumio[27834]: info: ___________ START PLUGINS ___________ Feb 19 03:01:32 volumio volumio[27834]: info: ControllerMpd::onStart: Initializing MPD Feb 19 03:01:32 volumio volumio[27834]: info: Creating MPD Configuration file Feb 19 03:01:32 volumio sudo[28002]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 03:01:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:01:32 volumio volumio[27834]: info: [1771444892828] CoreMusicLibrary::Adding element Media Servers Feb 19 03:01:32 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:01:32 volumio sudo[28015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 03:01:32 volumio sudo[28015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:32 volumio sudo[28015]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:32 volumio sudo[28017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 03:01:32 volumio sudo[28017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:32 volumio volumio[27834]: info: UPNP Browser: Client initialized successfully Feb 19 03:01:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 03:01:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 03:01:32 volumio systemd[1]: mpd.service: Consumed 7.210s CPU time. Feb 19 03:01:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 03:01:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 03:01:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 03:01:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 03:01:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 19 03:01:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 19 03:01:33 volumio volumio[27834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 19 03:01:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 19 03:01:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 19 03:01:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 19 03:01:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 19 03:01:33 volumio volumio[27834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:01:33 volumio volumio[27834]: info: [1771444893340] CoreMusicLibrary::Adding element Last_100 Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:01:33 volumio volumio[27834]: info: [1771444893359] CoreMusicLibrary::Adding element Webradio Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:01:33 volumio volumio[27834]: info: Initializing BBC Radios Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:33 volumio volumio[27834]: info: Creating Spotify config file Feb 19 03:01:33 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:33 volumio sudo[28029]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 19 03:01:33 volumio sudo[28029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 19 03:01:33 volumio sudo[28029]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:34 volumio volumio[27950]: Starting albumart workers Feb 19 03:01:34 volumio volumio[27948]: Starting albumart workers Feb 19 03:01:34 volumio volumio[27949]: Starting albumart workers Feb 19 03:01:34 volumio volumio[27834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:01:34 volumio volumio[27834]: info: [1771444894783] CoreMusicLibrary::Adding element YouTube Music Feb 19 03:01:34 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:01:34 volumio volumio[27834]: Cannot find translation for source YouTube Music Feb 19 03:01:34 volumio volumio[27834]: info: Volumio Calling Home Feb 19 03:01:34 volumio sudo[28049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 19 03:01:34 volumio sudo[28049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:35 volumio sudo[28049]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:35 volumio volumio[27834]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 03:01:35 volumio volumio[27834]: info: Discovery: Found device Volumio Feb 19 03:01:35 volumio volumio[27834]: info: CoreCommandRouter::volumioGetState Feb 19 03:01:35 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:35 volumio volumio[27834]: info: MPD Permissions set Feb 19 03:01:35 volumio volumio[27834]: info: MPD Permissions set Feb 19 03:01:35 volumio volumio[27834]: info: Upmpdcli Daemon Started Feb 19 03:01:35 volumio volumio[27834]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 19 03:01:35 volumio volumio[27834]: info: Discovery: Found device Volumio Feb 19 03:01:35 volumio volumio[27834]: info: CoreCommandRouter::volumioGetState Feb 19 03:01:35 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:36 volumio volumio[27834]: info: Volumio called home Feb 19 03:01:36 volumio volumio[27834]: info: Spotify config file written Feb 19 03:01:36 volumio sudo[28056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 19 03:01:36 volumio volumio[27834]: 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 19 03:01:36 volumio sudo[28056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 19 03:01:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:36 volumio go-librespot[28075]: go-librespot daemon starting... Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 03:01:36 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 03:01:36 volumio sudo[28056]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:36 volumio volumio[27834]: info: No need to fix Spotify hosts Feb 19 03:01:36 volumio go-librespot[28080]: time="2026-02-19T03:01:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:36 volumio go-librespot[28080]: time="2026-02-19T03:01:36+07:00" level=debug msg="app state loaded" Feb 19 03:01:36 volumio go-librespot[28080]: time="2026-02-19T03:01:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=info msg="zeroconf server listening on port 43785" Feb 19 03:01:37 volumio volumio[27834]: info: Starting Shairport Sync Feb 19 03:01:37 volumio volumio[27834]: info: Starting Shairport Sync Feb 19 03:01:37 volumio volumio[27834]: info: Starting Shairport Sync Feb 19 03:01:37 volumio sudo[28095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:01:37 volumio sudo[28095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="obtained new client token: AAD/9/UsY4vk9qkQGSULFGfLiXOwXQIkUDY/IVullFkc6U8FSnT6sz9Fq0f8NXikLD6vzahVvbGmkCxzHK68dFpFuIm2Oeq8BWrzUxaDnhgU1tWaGe3oGRt6+Soi+8Y53QB5LFSvipsXe3Cui0Ugzgz5q2c4bkGcUDDfxVXhxHu2IyksYbXrRBZ+UWemDbOoD3PTPypNA4OykQcnG+JjN/vAkXNX+zzustZp9/RKraaYr7htYCukzKdRvA==" Feb 19 03:01:37 volumio sudo[28097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:01:37 volumio sudo[28097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:37 volumio sudo[28100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 03:01:37 volumio sudo[28100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 19 03:01:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 03:01:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 03:01:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:01:37 volumio systemd[1]: shairport-sync.service: Consumed 2.313s CPU time. Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=debug msg="completed challenge" Feb 19 03:01:37 volumio sudo[28095]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:37 volumio go-librespot[28080]: time="2026-02-19T03:01:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:01:37 volumio volumio[27834]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 03:01:37 volumio volumio[27834]: SPOTIFY: BQC_hGwpyyewsyEzHIGZni4x-rLfLNltftbFqJ9HxnwZR-e4jux4jhnf9lzYNgLx64uxVkDxb-n9V2gdDdDDU5nCZUsrv0OyHffBN7vD8ZDs70bSJm_sVaY0Fwi3Gc1PodY8GJ_gWAhNM6-YBdZb9wkm7Tkt8neJD1l_LTX7p8dQguag_HRcJ4SxA337pYWIwYj3AKcb4DSrSIRLPOMROrigNu6vpVK1-fRgNKVExlhsoAiOCJcbc_ilanuadP8H23K7HDdIs0P17PW_JbnJdPDOCL4y5MCR6732XLUawvIIMFToZpgiCNPP Feb 19 03:01:37 volumio volumio[27834]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 19 03:01:37 volumio volumio[27834]: info: New Spotify access token = BQC_hGwpyyewsyEzHIGZni4x-rLfLNltftbFqJ9HxnwZR-e4jux4jhnf9lzYNgLx64uxVkDxb-n9V2gdDdDDU5nCZUsrv0OyHffBN7vD8ZDs70bSJm_sVaY0Fwi3Gc1PodY8GJ_gWAhNM6-YBdZb9wkm7Tkt8neJD1l_LTX7p8dQguag_HRcJ4SxA337pYWIwYj3AKcb4DSrSIRLPOMROrigNu6vpVK1-fRgNKVExlhsoAiOCJcbc_ilanuadP8H23K7HDdIs0P17PW_JbnJdPDOCL4y5MCR6732XLUawvIIMFToZpgiCNPP Feb 19 03:01:37 volumio volumio[27834]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 19 03:01:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 19 03:01:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 19 03:01:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:01:37 volumio volumio[27834]: info: CoreCommandRouter::volumioGetState Feb 19 03:01:37 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:38 volumio volumio[27834]: info: Shairport-Sync Started Feb 19 03:01:38 volumio volumio[27834]: Error adding Membership: Error: addMembership EINVAL Feb 19 03:01:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 19 03:01:38 volumio sudo[28097]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:38 volumio sudo[28100]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:38 volumio volumio[27834]: info: Shairport-Sync Started Feb 19 03:01:38 volumio volumio[27834]: info: Shairport-Sync Started Feb 19 03:01:38 volumio volumio[27834]: 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 19 03:01:38 volumio volumio[27834]: info: Spotify Successfully logged in Feb 19 03:01:38 volumio volumio[27834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 19 03:01:38 volumio volumio[27834]: info: [1771444898473] CoreMusicLibrary::Adding element Spotify Feb 19 03:01:38 volumio volumio[27834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 19 03:01:38 volumio volumio[27834]: Cannot find translation for source YouTube Music Feb 19 03:01:38 volumio volumio[27834]: Cannot find translation for source Spotify Feb 19 03:01:38 volumio volumio[27834]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 19 03:01:38 volumio volumio[27834]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 03:01:39 volumio volumio[27834]: info: VolumeController:: Volume=100 Mute =false Feb 19 03:01:39 volumio volumio[27834]: info: CoreCommandRouter::volumioGetState Feb 19 03:01:39 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:39 volumio volumio[27834]: info: CoreStateMachine::pushState Feb 19 03:01:39 volumio volumio[27834]: info: CorePlayQueue::getTrack 0 Feb 19 03:01:39 volumio volumio[27834]: info: CoreCommandRouter::volumioPushState Feb 19 03:01:40 volumio volumio[27834]: info: go-librespot daemon successfully initialized Feb 19 03:01:40 volumio mpd[28047]: 2026-02-19T03:01:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 19 03:01:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 19 03:01:40 volumio sudo[28017]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:40 volumio sudo[28006]: pam_unix(sudo:session): session closed for user root Feb 19 03:01:40 volumio volumio[27834]: error: MPD error: The expression evaluated to a falsy value: Feb 19 03:01:40 volumio volumio[27834]: assert.ok(self.idling) Feb 19 03:01:40 volumio volumio[27834]: error: The expression evaluated to a falsy value: Feb 19 03:01:40 volumio volumio[27834]: assert.ok(self.idling) Feb 19 03:01:40 volumio volumio[27834]: info: MPD running with PID28047 Feb 19 03:01:40 volumio volumio[27834]: ,establishing connection Feb 19 03:01:40 volumio volumio[27834]: error: updateQueue error: null Feb 19 03:01:40 volumio volumio[27834]: info: Completed starting Core Plugins Feb 19 03:01:40 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:40 volumio volumio[27834]: info: ----- MyVolumio plugins startup ---- Feb 19 03:01:40 volumio volumio[27834]: info: ------------------------------------------- Feb 19 03:01:40 volumio volumio[27834]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 19 03:01:40 volumio volumio[27834]: error: updateQueue error: null Feb 19 03:01:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 19 03:01:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:41 volumio go-librespot[28140]: go-librespot daemon starting... Feb 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01:41+07:00" level=debug msg="app state loaded" Feb 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01: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 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01: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 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01: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 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01:41+07:00" level=info msg="zeroconf server listening on port 42109" Feb 19 03:01:41 volumio go-librespot[28141]: time="2026-02-19T03:01:41+07:00" level=debug msg="obtained new client token: AACsVTwJu9iOHuRk62RvZsQzRRJ/1/MD2aoUfW4j8r9CYHDkFSEniMfWh+2H+5DmsRy2nmRWBju2h1R7o4B+XbuMVWU36006Y3WiQmGWSdrCyZrCiTyENcZPZa4VScLOOlNMkNUTgO0q2DmUKIy4FebDy2rlzSgawzBa3BhHQAFZzhHH0nHclyYeGgrQTdCIGJp2DqsfnZpbsRjuO3vp9bXE+kFp0KihF7KXSa5fSzyfr/ZfhpXFbTcgmA==" Feb 19 03:01:42 volumio go-librespot[28141]: time="2026-02-19T03:01:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:42 volumio go-librespot[28141]: time="2026-02-19T03:01:42+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:42 volumio go-librespot[28141]: time="2026-02-19T03:01:42+07:00" level=debug msg="completed challenge" Feb 19 03:01:42 volumio go-librespot[28141]: time="2026-02-19T03:01:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:01:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:43 volumio volumio[27834]: info: Initializing connection to go-librespot Websocket Feb 19 03:01:43 volumio volumio[27834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 03:01:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 19 03:01:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:45 volumio go-librespot[28148]: go-librespot daemon starting... Feb 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01:45+07:00" level=debug msg="app state loaded" Feb 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:45 volumio volumio[27834]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01: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 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01: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 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01: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 19 03:01:45 volumio go-librespot[28149]: time="2026-02-19T03:01:45+07:00" level=info msg="zeroconf server listening on port 46087" Feb 19 03:01:46 volumio go-librespot[28149]: time="2026-02-19T03:01:46+07:00" level=debug msg="obtained new client token: AAA0l38X2zNjbfyGtywm1Wpf4jgujcV74y7xxT89tWDEXhiSqMTluTb64usOTCgyd9/tiIJq7NgFsnMOacnq94BzdC6REtzJnlRBdrW7H03HinMfIpllJDkebs/sbi+u40wUq/ggvRWu4qPa4KvvdgJ71nxjYZtrhuLBEsLzve3gXMqsYCVqn+hUYJV/GPCpWK4dxmw5v+M3q2LghKZCpb2Eadi3NQr1QkUbCu27yan9uTgjUMYzHqo=" Feb 19 03:01:46 volumio go-librespot[28149]: time="2026-02-19T03:01:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:46 volumio go-librespot[28149]: time="2026-02-19T03:01:46+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:46 volumio go-librespot[28149]: time="2026-02-19T03:01:46+07:00" level=debug msg="completed challenge" Feb 19 03:01:46 volumio volumio[27834]: info: Initializing connection to go-librespot Websocket Feb 19 03:01:46 volumio go-librespot[28149]: time="2026-02-19T03:01:46+07:00" level=debug msg="new websocket client" Feb 19 03:01:46 volumio volumio[27834]: info: Connection to go-librespot Websocket established Feb 19 03:01:46 volumio go-librespot[28149]: time="2026-02-19T03:01: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 19 03:01:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:46 volumio volumio[27834]: info: Connection to go-librespot Websocket closed Feb 19 03:01:49 volumio volumio[27834]: info: Getting Spotify volume Feb 19 03:01:49 volumio volumio[27834]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 03:01:49 volumio volumio[27834]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 03:01:49 volumio volumio[27834]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 19 03:01:49 volumio volumio[27834]: errno: -111, Feb 19 03:01:49 volumio volumio[27834]: code: 'ECONNREFUSED', Feb 19 03:01:49 volumio volumio[27834]: syscall: 'connect', Feb 19 03:01:49 volumio volumio[27834]: address: '127.0.0.1', Feb 19 03:01:49 volumio volumio[27834]: port: 9879, Feb 19 03:01:49 volumio volumio[27834]: response: undefined Feb 19 03:01:49 volumio volumio[27834]: } Feb 19 03:01:49 volumio volumio[27834]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 03:01:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 19 03:01:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 19 03:01:49 volumio go-librespot[28159]: go-librespot daemon starting... Feb 19 03:01:49 volumio go-librespot[28168]: time="2026-02-19T03:01:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 19 03:01:49 volumio go-librespot[28168]: time="2026-02-19T03:01:49+07:00" level=debug msg="app state loaded" Feb 19 03:01:49 volumio go-librespot[28168]: time="2026-02-19T03:01:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+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 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+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 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+07:00" level=info msg="zeroconf server listening on port 32947" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+07:00" level=debug msg="obtained new client token: AADXA3rhVlib2cJY7wyHKwFzRKxH+14A3APj4+qmhzJTwE4wJfFIYdTijvM02F2XOgBIoEomfM/ZR1dcruTsTw4HsCsCIjbGEK79X1dLOgzR1QJyAv+rjkc2wYEyAEiB2a9yfZYEEvaYeRZDC5eA9HN2vlzY50AYik1hCDPZzRqJ40R9NffxypB/lAaHsw16/XcyKtSgrx6jCVdmSdtJxP2q5z7V1UyVGHmCz2pY4xk6Kkb74G9DHqQBLA==" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+07:00" level=debug msg="completed keyexchange" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+07:00" level=debug msg="completed challenge" Feb 19 03:01:50 volumio go-librespot[28168]: time="2026-02-19T03:01:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 19 03:01:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 19 03:01:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 03:01:50 volumio sudo[28193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 03:00' Feb 19 03:01:51 volumio sudo[28193]: 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"