Feb 13 09:07:00 volumio volumio-remote-updater[643]: [2026-02-13 09:07:00] [connect] Successful connection Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "outputs"... Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "albumart"... Feb 13 09:07:00 volumio volumio[24052]: info: Plugin example_plugin is not enabled Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "inputs"... Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "updater_comm"... Feb 13 09:07:00 volumio volumio[24052]: info: Plugin mpdemulation is not enabled Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "rest_api"... Feb 13 09:07:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 13 09:07:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "websocket"... Feb 13 09:07:00 volumio volumio[24052]: info: Starting Socket.io Server version 1.7.4 Feb 13 09:07:00 volumio volumio[24052]: info: Loading plugin "RoonBridge"... Feb 13 09:07:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:00 volumio go-librespot[24174]: go-librespot daemon starting... Feb 13 09:07:00 volumio go-librespot[24177]: time="2026-02-13T09:07:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:00 volumio go-librespot[24177]: time="2026-02-13T09:07:00+07:00" level=debug msg="app state loaded" Feb 13 09:07:00 volumio go-librespot[24177]: time="2026-02-13T09:07:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:01 volumio volumio[24052]: info: Applying required configuration parameters for plugin RoonBridge Feb 13 09:07:01 volumio volumio[24052]: info: Loading i18n strings for locale en Feb 13 09:07:01 volumio volumio[24052]: Updating browse sources language Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:01 volumio go-librespot[24177]: time="2026-02-13T09:07: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 13 09:07:01 volumio go-librespot[24177]: time="2026-02-13T09:07: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 13 09:07:01 volumio go-librespot[24177]: time="2026-02-13T09:07: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 13 09:07:01 volumio go-librespot[24177]: time="2026-02-13T09:07:01+07:00" level=info msg="zeroconf server listening on port 45041" Feb 13 09:07:01 volumio volumio[24164]: Forking 3 albumart workers Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::initPlayerControls Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:07:01 volumio volumio[24052]: Express server listening on port 3000 Feb 13 09:07:01 volumio volumio[24052]: [Metrics] WebUI: 16s 122.15ms Feb 13 09:07:01 volumio volumio[24052]: info: CoreStateMachine::resetVolumioState Feb 13 09:07:01 volumio volumio[24052]: info: CoreStateMachine::getcurrentVolume Feb 13 09:07:01 volumio volumio[24052]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:07:01 volumio go-librespot[24177]: time="2026-02-13T09:07:01+07:00" level=debug msg="obtained new client token: AABYqr1pC+jsRqDg4uAOLflsCMR4G6W/+dD+ub//ATjJpJGx79ENNpMw7OlOxY3/LOLa7aC0HkiRYQsBhv5CYuOmnTHXaBHhb0B/XBFAcvJblKoTrpv5Kjbim9ide94gpTzXvq7zVkzja0bU2RkSTYIVNaBvEvioIBDAY889KdebwSq38cKsmsLGddJtKIY7NRk1C7/CBpbhoCvcQClE8u4fDgATh+UEJ72+bG66mw7oBSOWMtD8rxsRVg==" Feb 13 09:07:01 volumio sudo[24217]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 09:07:01 volumio sudo[24217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:01 volumio sudo[24219]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 09:07:01 volumio sudo[24219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:01 volumio sudo[24217]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:01 volumio go-librespot[24177]: time="2026-02-13T09:07:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:01 volumio sudo[24219]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:01 volumio volumio[24052]: info: Volumio Network Manager: Network status updated: 1 Feb 13 09:07:02 volumio go-librespot[24177]: time="2026-02-13T09:07:02+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:02 volumio go-librespot[24177]: time="2026-02-13T09:07:02+07:00" level=debug msg="completed challenge" Feb 13 09:07:02 volumio go-librespot[24177]: time="2026-02-13T09:07: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 13 09:07:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:02 volumio volumio[24052]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::pushState Feb 13 09:07:02 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::updateTrackBlock Feb 13 09:07:02 volumio volumio[24052]: info: CorePlayQueue::getTrackBlock Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:07:02 volumio volumio-remote-updater[643]: [2026-02-13 09:07:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770948420 101 Feb 13 09:07:02 volumio volumio[24052]: 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 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:02 volumio volumio[24052]: info: Reloading queue from file Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::setRepeat null single undefined Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::pushState Feb 13 09:07:02 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::setRandom null Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::pushState Feb 13 09:07:02 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:02 volumio volumio[24052]: info: Setting Device type: Raspberry PI Feb 13 09:07:02 volumio volumio[24052]: info: Completed loading Core Plugins Feb 13 09:07:02 volumio volumio[24052]: info: Preparing to generate the ALSA configuration file Feb 13 09:07:02 volumio volumio[24052]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:07:02 volumio volumio[24052]: info: CoreStateMachine::pushState Feb 13 09:07:02 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:02 volumio volumio[24052]: info: Asound.conf file unchanged, so no further update is needed Feb 13 09:07:02 volumio volumio[24052]: info: Output device has changed, restarting MPD Feb 13 09:07:02 volumio sudo[24235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 13 09:07:02 volumio sudo[24235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:02 volumio volumio[24052]: info: Output device has changed, restarting Shairport Sync Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:02 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:02 volumio sudo[24237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 09:07:02 volumio sudo[24237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:02 volumio sudo[24237]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:02 volumio sudo[24235]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:02 volumio sudo[24239]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 09:07:02 volumio sudo[24239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:02 volumio volumio[24052]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:07:02 volumio volumio[24052]: info: ___________ START PLUGINS ___________ Feb 13 09:07:02 volumio volumio[24052]: info: ControllerMpd::onStart: Initializing MPD Feb 13 09:07:02 volumio volumio[24052]: info: Creating MPD Configuration file Feb 13 09:07:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:03 volumio volumio[24052]: info: [1770948423030] CoreMusicLibrary::Adding element Media Servers Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:03 volumio sudo[24248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 09:07:03 volumio sudo[24248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:03 volumio sudo[24248]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:03 volumio sudo[24250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 09:07:03 volumio sudo[24250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:03 volumio volumio[24052]: info: UPNP Browser: Client initialized successfully Feb 13 09:07:03 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 09:07:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 09:07:03 volumio systemd[1]: mpd.service: Consumed 7.127s CPU time. Feb 13 09:07:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 09:07:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 09:07:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 09:07:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 09:07:03 volumio volumio[24052]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:03 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 09:07:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 09:07:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 09:07:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 09:07:03 volumio volumio[24052]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:03 volumio volumio[24052]: info: [1770948423395] CoreMusicLibrary::Adding element Last_100 Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:03 volumio volumio[24052]: info: [1770948423405] CoreMusicLibrary::Adding element Webradio Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 09:07:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:07:03 volumio volumio[24052]: info: Initializing BBC Radios Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:03 volumio volumio[24052]: info: Creating Spotify config file Feb 13 09:07:03 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:03 volumio sudo[24264]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 13 09:07:03 volumio sudo[24264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 13 09:07:03 volumio sudo[24264]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:04 volumio volumio[24052]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:04 volumio volumio[24052]: info: [1770948424895] CoreMusicLibrary::Adding element YouTube Music Feb 13 09:07:04 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:04 volumio volumio[24052]: Cannot find translation for source YouTube Music Feb 13 09:07:04 volumio volumio[24187]: Starting albumart workers Feb 13 09:07:04 volumio volumio[24052]: info: Volumio Calling Home Feb 13 09:07:04 volumio volumio[24185]: Starting albumart workers Feb 13 09:07:05 volumio sudo[24281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 13 09:07:05 volumio sudo[24281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:05 volumio sudo[24281]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:05 volumio volumio[24186]: Starting albumart workers Feb 13 09:07:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 13 09:07:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:05 volumio go-librespot[24286]: go-librespot daemon starting... Feb 13 09:07:05 volumio go-librespot[24287]: time="2026-02-13T09:07:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:06 volumio volumio[24052]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 09:07:06 volumio volumio[24052]: info: Discovery: Found device Volumio Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:06 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:06 volumio volumio[24052]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 09:07:06 volumio volumio[24052]: info: Discovery: Found device Volumio Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:06 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:06 volumio go-librespot[24287]: time="2026-02-13T09:07:06+07:00" level=info msg="zeroconf server listening on port 46355" Feb 13 09:07:06 volumio volumio[24052]: info: MPD Permissions set Feb 13 09:07:06 volumio volumio[24052]: info: MPD Permissions set Feb 13 09:07:06 volumio volumio[24052]: info: Upmpdcli Daemon Started Feb 13 09:07:06 volumio volumio[24052]: info: Volumio called home Feb 13 09:07:06 volumio volumio[24052]: info: Spotify config file written Feb 13 09:07:06 volumio volumio[24052]: 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 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio sudo[24296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 13 09:07:06 volumio sudo[24296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:06 volumio volumio[24052]: info: No need to fix Spotify hosts Feb 13 09:07:06 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 13 09:07:06 volumio systemd[1]: go-librespot-daemon.service: Killing process 24288 (go-librespot) with signal SIGKILL. Feb 13 09:07:06 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 13 09:07:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:06 volumio go-librespot[24308]: go-librespot daemon starting... Feb 13 09:07:06 volumio sudo[24296]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:06 volumio go-librespot[24309]: time="2026-02-13T09:07:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:06 volumio go-librespot[24309]: time="2026-02-13T09:07:06+07:00" level=debug msg="app state loaded" Feb 13 09:07:06 volumio go-librespot[24309]: time="2026-02-13T09:07:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:07 volumio go-librespot[24309]: time="2026-02-13T09:07:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:07:07 volumio go-librespot[24309]: time="2026-02-13T09:07:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 13 09:07:07 volumio go-librespot[24309]: time="2026-02-13T09:07:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 13 09:07:07 volumio go-librespot[24309]: time="2026-02-13T09:07:07+07:00" level=info msg="zeroconf server listening on port 44119" Feb 13 09:07:07 volumio go-librespot[24309]: time="2026-02-13T09:07:07+07:00" level=debug msg="obtained new client token: AAAFkHVjWz4IM1Lxx7MEyDl/TMyQkjP2HoNv6WnvcQHUCxH5mGCbT9bcB5AO0D/BtMBr4td/6K9bxTPr63K3zVUH2u3AnP8f2TyjcVW0fzh1ugqzfx1Ccu4BBOcvVayFKHCSn8+xundBYGjqNeW+HbSCb6sBbA6FwGqSM8nw4VANxy/YTTJxdzyntO9iFrwcA7r6XI4ceewv58OpMUxj04eTMzaOiDF8aPpPFPgz1UDAfcYbLAeCnNhQbQ==" Feb 13 09:07:07 volumio go-librespot[24309]: time="2026-02-13T09:07:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:07 volumio volumio[24052]: info: Starting Shairport Sync Feb 13 09:07:07 volumio volumio[24052]: info: Starting Shairport Sync Feb 13 09:07:08 volumio volumio[24052]: info: Starting Shairport Sync Feb 13 09:07:08 volumio go-librespot[24309]: time="2026-02-13T09:07:08+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:08 volumio go-librespot[24309]: time="2026-02-13T09:07:08+07:00" level=debug msg="completed challenge" Feb 13 09:07:08 volumio sudo[24335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:07:08 volumio sudo[24335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:08 volumio sudo[24337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:07:08 volumio sudo[24337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:08 volumio go-librespot[24309]: time="2026-02-13T09:07:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:07:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:08 volumio sudo[24339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:07:08 volumio sudo[24339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:08 volumio volumio[24052]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 09:07:08 volumio volumio[24052]: SPOTIFY: BQBKuhGyjPrOmNH5vdclhVkDECUvOSD80zTbpbisAX-TqASt4mLkpgs340Om_9fqkdDcCsNQoh7JL-fFrL-UAZMjULocZ_WwoxknQrGrax_VaSaR2has4Rgi29VU3o7f47s1E5KBfzw24FDbodP1PzVKQncW-hqZ71HemZCUOjEQtY4vebws-iUVRUPKWWcyp3VYjLoPSfzeyEoKvgKf1E48uxdLbPdSP-EEN7reNBLGF_uTKscvcd8DeLR7cTKMNmElgQN-LpLE6oVU9NItpuX2PrKknq-N2pZexBWTUZs3G_zsMhDP6fmx Feb 13 09:07:08 volumio volumio[24052]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 09:07:08 volumio volumio[24052]: info: New Spotify access token = BQBKuhGyjPrOmNH5vdclhVkDECUvOSD80zTbpbisAX-TqASt4mLkpgs340Om_9fqkdDcCsNQoh7JL-fFrL-UAZMjULocZ_WwoxknQrGrax_VaSaR2has4Rgi29VU3o7f47s1E5KBfzw24FDbodP1PzVKQncW-hqZ71HemZCUOjEQtY4vebws-iUVRUPKWWcyp3VYjLoPSfzeyEoKvgKf1E48uxdLbPdSP-EEN7reNBLGF_uTKscvcd8DeLR7cTKMNmElgQN-LpLE6oVU9NItpuX2PrKknq-N2pZexBWTUZs3G_zsMhDP6fmx Feb 13 09:07:08 volumio volumio[24052]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 13 09:07:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 13 09:07:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 13 09:07:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 09:07:08 volumio systemd[1]: shairport-sync.service: Consumed 2.292s CPU time. Feb 13 09:07:08 volumio volumio[24052]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:08 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 09:07:08 volumio sudo[24339]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:08 volumio sudo[24337]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:08 volumio sudo[24335]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:08 volumio volumio[24052]: info: Shairport-Sync Started Feb 13 09:07:08 volumio volumio[24052]: Error adding Membership: Error: addMembership EINVAL Feb 13 09:07:08 volumio volumio[24052]: info: Shairport-Sync Started Feb 13 09:07:08 volumio volumio[24052]: info: Shairport-Sync Started Feb 13 09:07:08 volumio volumio[24052]: 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 13 09:07:08 volumio volumio[24052]: info: Spotify Successfully logged in Feb 13 09:07:08 volumio volumio[24052]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:08 volumio volumio[24052]: info: [1770948428755] CoreMusicLibrary::Adding element Spotify Feb 13 09:07:08 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:08 volumio volumio[24052]: Cannot find translation for source YouTube Music Feb 13 09:07:08 volumio volumio[24052]: Cannot find translation for source Spotify Feb 13 09:07:09 volumio volumio[24052]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 13 09:07:09 volumio volumio[24052]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:07:09 volumio volumio[24052]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:07:09 volumio volumio[24052]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:09 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:09 volumio volumio[24052]: info: CoreStateMachine::pushState Feb 13 09:07:09 volumio volumio[24052]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:09 volumio volumio[24052]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:10 volumio volumio[24052]: info: go-librespot daemon successfully initialized Feb 13 09:07:11 volumio mpd[24279]: 2026-02-13T09:07:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 13 09:07:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 13 09:07:11 volumio sudo[24239]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:11 volumio sudo[24250]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:11 volumio volumio[24052]: error: MPD error: The expression evaluated to a falsy value: Feb 13 09:07:11 volumio volumio[24052]: assert.ok(self.idling) Feb 13 09:07:11 volumio volumio[24052]: error: The expression evaluated to a falsy value: Feb 13 09:07:11 volumio volumio[24052]: assert.ok(self.idling) Feb 13 09:07:11 volumio volumio[24052]: info: MPD running with PID24279 Feb 13 09:07:11 volumio volumio[24052]: ,establishing connection Feb 13 09:07:11 volumio volumio[24052]: error: updateQueue error: null Feb 13 09:07:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 13 09:07:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:11 volumio volumio[24052]: info: Completed starting Core Plugins Feb 13 09:07:11 volumio volumio[24052]: info: ------------------------------------------- Feb 13 09:07:11 volumio volumio[24052]: info: ----- MyVolumio plugins startup ---- Feb 13 09:07:11 volumio volumio[24052]: info: ------------------------------------------- Feb 13 09:07:11 volumio volumio[24052]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 13 09:07:11 volumio volumio[24052]: error: updateQueue error: null Feb 13 09:07:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:11 volumio go-librespot[24380]: go-librespot daemon starting... Feb 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+07:00" level=debug msg="app state loaded" Feb 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+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 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+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 13 09:07:11 volumio go-librespot[24381]: time="2026-02-13T09:07:11+07:00" level=info msg="zeroconf server listening on port 44349" Feb 13 09:07:12 volumio go-librespot[24381]: time="2026-02-13T09:07:12+07:00" level=debug msg="obtained new client token: AABiBHfD9NZnUsc5xnU0ZYyQ9IaGUjXon3KhUYfnoGgcdlfOGrTqgNZK1ksdQS1hmHVez1LYbutOiH4VEtPW4U1ErWL5JYKBpr95CbQCzlG4Bdf5al+Tdhy0XPgON51CXv7iAT9HUXekRckzeGGFUzTdI7osOS79MAeQoyz7KSgTUh5KmeUs1FCCTAAIAooZr0zJGOxCGWNBaFVWn/KQtnwgYmAXUU4Qu9dCkTPiSL+gaNhPrafH1Qw=" Feb 13 09:07:12 volumio go-librespot[24381]: time="2026-02-13T09:07:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:12 volumio go-librespot[24381]: time="2026-02-13T09:07:12+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:12 volumio go-librespot[24381]: time="2026-02-13T09:07:12+07:00" level=debug msg="completed challenge" Feb 13 09:07:12 volumio go-librespot[24381]: time="2026-02-13T09:07:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:07:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:13 volumio volumio[24052]: info: Initializing connection to go-librespot Websocket Feb 13 09:07:13 volumio volumio[24052]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:07:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 13 09:07:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:15 volumio go-librespot[24389]: go-librespot daemon starting... Feb 13 09:07:15 volumio go-librespot[24390]: time="2026-02-13T09:07:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:15 volumio go-librespot[24390]: time="2026-02-13T09:07:15+07:00" level=debug msg="app state loaded" Feb 13 09:07:15 volumio go-librespot[24390]: time="2026-02-13T09:07:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:16 volumio volumio[24052]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=info msg="zeroconf server listening on port 36943" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="obtained new client token: AAAUssKfuITdouU36mSGqAF3W9kma5cvIG4KyP6ZWlKvgeixpgCaHaJ8kAHNRa/clKhE5R3nOO7Gutqqm+dhdFIEeASBnFyeW1j0Ls7WVOYkOe7tt1wabF/e7cCJO1SimRuVqzAeButMAgD1D/OxgMxTXKs8w+py88bWo3ZikTDqgzY2C0gx036GwKkjPVtUH22UtPTGTurjN5elEr548kErV2N1qca6F1rT+uc5PRDno4tOd/HXoowtPA==" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=debug msg="completed challenge" Feb 13 09:07:16 volumio go-librespot[24390]: time="2026-02-13T09:07:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:07:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:16 volumio volumio[24052]: info: Initializing connection to go-librespot Websocket Feb 13 09:07:16 volumio volumio[24052]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:07:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 13 09:07:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:19 volumio go-librespot[24397]: go-librespot daemon starting... Feb 13 09:07:19 volumio go-librespot[24398]: time="2026-02-13T09:07:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:19 volumio go-librespot[24398]: time="2026-02-13T09:07:19+07:00" level=debug msg="app state loaded" Feb 13 09:07:19 volumio go-librespot[24398]: time="2026-02-13T09:07:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:19 volumio volumio[24052]: info: Initializing connection to go-librespot Websocket Feb 13 09:07:19 volumio go-librespot[24398]: time="2026-02-13T09:07:19+07:00" level=debug msg="new websocket client" Feb 13 09:07:19 volumio volumio[24052]: info: Connection to go-librespot Websocket established Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin bluetooth to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin multiroom to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin metavolumio to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin cd_controller to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 13 09:07:20 volumio volumio[24052]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+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 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+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 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=info msg="zeroconf server listening on port 42521" Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=debug msg="obtained new client token: AAB+k3169E2KhXVgWg6XSIBwlgEXGn3bCgL7nFyDxXgfrHTIokPri8JjVL2Anw6Gs7eqlVVvyTXrSyXTrIGDzar4dMylpEGh6w2/KrcAgXpa/46VDVUDHiRuB+8WB8dr4pIyk+34i4pZ9msncbUvVpBu0FWnhh8FYf7uXCcjTaW1KhafEJHQy+IbG6sB/gIzE7GAnQiBc+6q4kI3AgP9e2oGpKX55Xv5k9zqZIDEvMSo27v+Dh7jYN6qkg==" Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=debug msg="completed challenge" Feb 13 09:07:20 volumio go-librespot[24398]: time="2026-02-13T09:07:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:07:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:21 volumio volumio[24052]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 13 09:07:21 volumio volumio[24052]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 13 09:07:21 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:21 volumio volumio[24052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:21 volumio volumio[24052]: info: Starting MyVolumio Remote Streaming Endpoints Feb 13 09:07:22 volumio volumio[24052]: info: MyVolumio login type: Token Feb 13 09:07:22 volumio volumio[24052]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 13 09:07:22 volumio volumio[24052]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 13 09:07:23 volumio volumio[24052]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 13 09:07:23 volumio volumio[24052]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 13 09:07:23 volumio volumio[24052]: info: Streaming services startup Feb 13 09:07:23 volumio volumio[24052]: info: Starting Streaming Daemon Feb 13 09:07:23 volumio sudo[24420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 13 09:07:23 volumio volumio[24052]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 13 09:07:23 volumio sudo[24420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:23 volumio sudo[24420]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:23 volumio volumio[24052]: info: Getting Spotify volume Feb 13 09:07:24 volumio volumio[24052]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 09:07:24 volumio volumio[24052]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:07:24 volumio volumio[24052]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 13 09:07:24 volumio volumio[24052]: errno: -111, Feb 13 09:07:24 volumio volumio[24052]: code: 'ECONNREFUSED', Feb 13 09:07:24 volumio volumio[24052]: syscall: 'connect', Feb 13 09:07:24 volumio volumio[24052]: address: '127.0.0.1', Feb 13 09:07:24 volumio volumio[24052]: port: 9879, Feb 13 09:07:24 volumio volumio[24052]: response: undefined Feb 13 09:07:24 volumio volumio[24052]: } Feb 13 09:07:24 volumio volumio[24052]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 09:07:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 13 09:07:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:24 volumio go-librespot[24430]: go-librespot daemon starting... Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=debug msg="app state loaded" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=info msg="zeroconf server listening on port 34815" Feb 13 09:07:24 volumio go-librespot[24439]: time="2026-02-13T09:07:24+07:00" level=debug msg="obtained new client token: AACZnF0N/ib8UBuFgPaSR8MKFAE55ijsJXxSPjNzCmXW8E1jOjt/itj+dO+H68MqAXtarp4JaHn4cuw7+B9jCX09CxzH9Fo0zfsKWYvTlkGEuqQ8tt1i0U+9JE8jtRLUu6F5NP4N65IBmdCZnNvKCW0F8bhemjktc87p21/AQtczQO+4tRigbKMZE4pQJ/Wppd2h1MX/q4zBBGD6smORv9lIcZ8QnGv8OUsvEa4xxVOszgBkQfHpVDbeMQ==" Feb 13 09:07:25 volumio go-librespot[24439]: time="2026-02-13T09:07:25+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 13 09:07:25 volumio go-librespot[24439]: time="2026-02-13T09:07:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 13 09:07:25 volumio go-librespot[24439]: time="2026-02-13T09:07:25+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:25 volumio go-librespot[24439]: time="2026-02-13T09:07:25+07:00" level=debug msg="completed challenge" Feb 13 09:07:25 volumio go-librespot[24439]: time="2026-02-13T09:07:25+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 13 09:07:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:25 volumio sudo[24449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 09:06' Feb 13 09:07:25 volumio sudo[24449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:25 volumio sudo[24449]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:27 volumio volumio-remote-updater[643]: [2026-02-13 09:07:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 13 09:07:27 volumio volumio-remote-updater[643]: [2026-02-13 09:07:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 13 09:07:27 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:27 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 13 09:07:27 volumio systemd[1]: volumio.service: Consumed 55.327s CPU time. Feb 13 09:07:27 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 13 09:07:27 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 13 09:07:27 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14498. Feb 13 09:07:27 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 13 09:07:27 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 13 09:07:27 volumio systemd[1]: volumio.service: Consumed 55.327s CPU time. Feb 13 09:07:27 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 13 09:07:27 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 13 09:07:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 13 09:07:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:28 volumio go-librespot[24482]: go-librespot daemon starting... Feb 13 09:07:28 volumio go-librespot[24483]: time="2026-02-13T09:07:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:28 volumio go-librespot[24483]: time="2026-02-13T09:07:28+07:00" level=debug msg="app state loaded" Feb 13 09:07:28 volumio go-librespot[24483]: time="2026-02-13T09:07:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+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 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+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 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+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 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+07:00" level=info msg="zeroconf server listening on port 45131" Feb 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+07:00" level=debug msg="obtained new client token: AAAKYxzebSvkIiVt9Zf3l1IfgLoQucHVDMstHlJKIHqJ7CPoD3ST6AC8/9kgQ/C3XLcnckVDQrHoLOpmHRBR0XzZGLLKTNDwCTg+CYwLOgew+WXxEJXtPekRmdONEqnRkPVD2Y23qmKKi1CfHAgCRKOjxGLGm8jD1cS3kRHUPUEhNVVbwISKPPINgHsxsWtuBe+dpcmKJJtN/1g+fSsz7m6CDWcq4xh2oXHgwvAnPSuUi9m/HGEhJzqhRg==" Feb 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+07:00" level=debug msg="completed challenge" Feb 13 09:07:29 volumio go-librespot[24483]: time="2026-02-13T09:07:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:07:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:31 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:31 volumio volumio[24467]: info: ----- Volumio3 ---- Feb 13 09:07:31 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:31 volumio volumio[24467]: info: ----- System startup ---- Feb 13 09:07:31 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:32 volumio volumio-remote-updater[643]: [2026-02-13 09:07:32] [connect] Successful connection Feb 13 09:07:32 volumio volumio[24467]: info: MYVOLUMIO Environment detected Feb 13 09:07:32 volumio volumio[24467]: info: Plugin folders cleanup Feb 13 09:07:32 volumio volumio[24467]: info: Scanning into folder /volumio/app/plugins/ Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category audio_interface Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category miscellanea Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category music_service Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category plugins.json Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category system_controller Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category user_interface Feb 13 09:07:32 volumio volumio[24467]: info: Scanning into folder /data/plugins/ Feb 13 09:07:32 volumio volumio[24467]: info: Scanning category music_service Feb 13 09:07:32 volumio volumio[24467]: info: Plugin folders cleanup completed Feb 13 09:07:32 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:32 volumio volumio[24467]: info: ----- Core plugins startup ---- Feb 13 09:07:32 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:32 volumio volumio[24467]: info: Loading plugins from folder /volumio/app/plugins/ Feb 13 09:07:32 volumio volumio[24467]: info: Adding plugin upnp to MyMusic Plugins Feb 13 09:07:32 volumio volumio[24467]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 13 09:07:32 volumio volumio[24467]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 13 09:07:32 volumio volumio[24467]: info: Loading plugins from folder /data/plugins/ Feb 13 09:07:32 volumio volumio[24467]: info: Loading plugin "system"... Feb 13 09:07:32 volumio volumio[24467]: info: Loading plugin "appearance"... Feb 13 09:07:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 13 09:07:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:32 volumio go-librespot[24503]: go-librespot daemon starting... Feb 13 09:07:32 volumio go-librespot[24504]: time="2026-02-13T09:07:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:32 volumio go-librespot[24504]: time="2026-02-13T09:07:32+07:00" level=debug msg="app state loaded" Feb 13 09:07:32 volumio go-librespot[24504]: time="2026-02-13T09:07:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+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 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+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 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+07:00" level=info msg="zeroconf server listening on port 36189" Feb 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+07:00" level=debug msg="obtained new client token: AAAGkvsucOShs78VzK1Uffd+OMLsTZFKvFG3oVshgtakA9nbsKgPUaea+/68uv/b9WzyDFQW+oUn89cKjidoy3CjJ7B4RV4gsFJ1v/RgWhbEYyK8F368DqEhMOMtsFGD/He62t1nTSvI9fUnNy7BxWTIUfrI0y96ONS+oIPYCUB6TcLmuqHoUYpEPUGZqrEMmNZ6Ih8MnY+PGfpvTZRfaqF+JYdHv4ZyeaN0AmpOcNGf8Bmm0IlTbBNDjQ==" Feb 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:33 volumio go-librespot[24504]: time="2026-02-13T09:07:33+07:00" level=debug msg="completed challenge" Feb 13 09:07:34 volumio go-librespot[24504]: time="2026-02-13T09:07:34+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 13 09:07:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:34 volumio volumio[24467]: info: Loading plugin "network"... Feb 13 09:07:34 volumio volumio[24467]: info: Refreshing Cached IP Addresses Feb 13 09:07:34 volumio sudo[24512]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 09:07:34 volumio sudo[24512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:34 volumio sudo[24512]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:34 volumio sudo[24514]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 09:07:34 volumio sudo[24514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:34 volumio volumio[24467]: info: Loading plugin "services"... Feb 13 09:07:34 volumio sudo[24514]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:34 volumio volumio[24467]: info: Loading plugin "alsa_controller"... Feb 13 09:07:34 volumio sudo[24522]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 13 09:07:34 volumio sudo[24522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:35 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "wizard"... Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "networkfs"... Feb 13 09:07:35 volumio volumio[24467]: info: Starting Udev Watcher for removable devices Feb 13 09:07:35 volumio volumio[24467]: info: Ignoring mount for partition: boot Feb 13 09:07:35 volumio volumio[24467]: info: Ignoring mount for partition: volumio Feb 13 09:07:35 volumio volumio[24467]: info: Ignoring mount for partition: volumio_data Feb 13 09:07:35 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "volumio_command_line_client"... Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "upnp"... Feb 13 09:07:35 volumio volumio[24467]: info: [1770948455184] Starting Upmpd Daemon Feb 13 09:07:35 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "my_music"... Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "mpd"... Feb 13 09:07:35 volumio volumio[24467]: info: Loading plugin "upnp_browser"... Feb 13 09:07:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 13 09:07:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:37 volumio go-librespot[24545]: go-librespot daemon starting... Feb 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07:37+07:00" level=debug msg="app state loaded" Feb 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:37 volumio sudo[24522]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07: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 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07: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 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07: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 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07:37+07:00" level=info msg="zeroconf server listening on port 41879" Feb 13 09:07:37 volumio go-librespot[24546]: time="2026-02-13T09:07:37+07:00" level=debug msg="obtained new client token: AAC7F3OAA83MBW2xUwR8JpgSAJjfDUbMqxmwzVPJMWQMaeMdXqLxTFwdPbj+DhJtV1aU9C9KZmopk4st0hP454f/NimrHpYvyT7EiYnVmTJxerMtaD2U/SC+8iM+FKYEW0qS53D0Jbdgnf3ZGGQdXXykA8Ksi1l7VUUPrv4oVY46d1lWsW3Ab6nbp1aqQxIO6C1OwmolZe0++HouI87TIdIX3q6sJgTpO9s1VmKgygrnJVT34/4VHZ6+Ww==" Feb 13 09:07:38 volumio go-librespot[24546]: time="2026-02-13T09:07:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:38 volumio go-librespot[24546]: time="2026-02-13T09:07:38+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:38 volumio go-librespot[24546]: time="2026-02-13T09:07:38+07:00" level=debug msg="completed challenge" Feb 13 09:07:38 volumio go-librespot[24546]: time="2026-02-13T09:07:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:07:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:38 volumio volumio[24467]: info: Starting UPNP Browser Feb 13 09:07:38 volumio volumio[24467]: info: Loading plugin "alarm-clock"... Feb 13 09:07:39 volumio volumio[24467]: info: Loading plugin "airplay_emulation"... Feb 13 09:07:39 volumio volumio[24467]: info: Starting Shairport Sync Feb 13 09:07:39 volumio volumio[24467]: info: Loading plugin "last_100"... Feb 13 09:07:39 volumio volumio[24467]: info: Loading plugin "webradio"... Feb 13 09:07:39 volumio volumio[24467]: info: Loading plugin "i2s_dacs"... Feb 13 09:07:39 volumio volumio[24467]: info: Loading plugin "volumiodiscovery"... Feb 13 09:07:39 volumio volumio[24467]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 09:07:39 volumio volumio[24467]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:07:39 volumio node[24467]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 09:07:39 volumio volumio[24467]: *** WARNING *** For more information see Feb 13 09:07:39 volumio volumio[24467]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 09:07:39 volumio volumio[24467]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:07:39 volumio volumio[24467]: *** WARNING *** For more information see Feb 13 09:07:39 volumio node[24467]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:07:39 volumio node[24467]: *** WARNING *** For more information see Feb 13 09:07:39 volumio node[24467]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 09:07:39 volumio node[24467]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:07:39 volumio node[24467]: *** WARNING *** For more information see Feb 13 09:07:39 volumio volumio[24467]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 13 09:07:39 volumio volumio[24467]: info: Discovery: Started advertising with name: Volumio Feb 13 09:07:39 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 09:07:39 volumio volumio[24467]: info: Loading plugin "spop"... Feb 13 09:07:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 13 09:07:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:41 volumio volumio[24467]: info: Loading plugin "ytcr"... Feb 13 09:07:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:41 volumio go-librespot[24555]: go-librespot daemon starting... Feb 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07:41+07:00" level=debug msg="app state loaded" Feb 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07:41+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 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07:41+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 13 09:07:41 volumio go-librespot[24556]: time="2026-02-13T09:07:41+07:00" level=info msg="zeroconf server listening on port 40995" Feb 13 09:07:42 volumio go-librespot[24556]: time="2026-02-13T09:07:42+07:00" level=debug msg="obtained new client token: AAD1k5y05iL31cMtasaCWs5MqVZzgC/bCjmZpKO92PkMA6rhNMzTcNsjRHnMcpFqgfT1sijE1xWh1bWkQ+s/9JjE6/qiAq5/EGNHhOldYsWC1YZ7yOkQYI0HdWLNl9He71spGVS+iKlaIPM+bN1+4Z1tO+z0mxNpyK50+9W1uQC7kccbZqX0QwRNptOy/wrqq8gK/XSFfmutUEQ/LbtmpelaN0bANrJRyh85M76K5eBC6wMRcQLsLxI=" Feb 13 09:07:42 volumio go-librespot[24556]: time="2026-02-13T09:07:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:42 volumio go-librespot[24556]: time="2026-02-13T09:07:42+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:42 volumio go-librespot[24556]: time="2026-02-13T09:07:42+07:00" level=debug msg="completed challenge" Feb 13 09:07:42 volumio go-librespot[24556]: time="2026-02-13T09:07: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 13 09:07:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:44 volumio volumio[24467]: info: Loading plugin "ytmusic"... Feb 13 09:07:44 volumio volumio-remote-updater[643]: [2026-02-13 09:07:44] [connect] Successful connection Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "outputs"... Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "albumart"... Feb 13 09:07:45 volumio volumio[24467]: info: Plugin example_plugin is not enabled Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "inputs"... Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "updater_comm"... Feb 13 09:07:45 volumio volumio[24467]: info: Plugin mpdemulation is not enabled Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "rest_api"... Feb 13 09:07:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 13 09:07:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "websocket"... Feb 13 09:07:45 volumio volumio[24467]: info: Starting Socket.io Server version 1.7.4 Feb 13 09:07:45 volumio volumio[24467]: info: Loading plugin "RoonBridge"... Feb 13 09:07:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:45 volumio go-librespot[24589]: go-librespot daemon starting... Feb 13 09:07:45 volumio go-librespot[24590]: time="2026-02-13T09:07:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:45 volumio go-librespot[24590]: time="2026-02-13T09:07:45+07:00" level=debug msg="app state loaded" Feb 13 09:07:45 volumio go-librespot[24590]: time="2026-02-13T09:07:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:45 volumio volumio[24467]: info: Applying required configuration parameters for plugin RoonBridge Feb 13 09:07:46 volumio volumio[24467]: info: Loading i18n strings for locale en Feb 13 09:07:46 volumio volumio[24467]: Updating browse sources language Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+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 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+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 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+07:00" level=info msg="zeroconf server listening on port 34893" Feb 13 09:07:46 volumio volumio[24579]: Forking 3 albumart workers Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::initPlayerControls Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:07:46 volumio volumio[24467]: Express server listening on port 3000 Feb 13 09:07:46 volumio volumio[24467]: [Metrics] WebUI: 16s 150.39ms Feb 13 09:07:46 volumio volumio[24467]: info: CoreStateMachine::resetVolumioState Feb 13 09:07:46 volumio volumio[24467]: info: CoreStateMachine::getcurrentVolume Feb 13 09:07:46 volumio volumio[24467]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+07:00" level=debug msg="obtained new client token: AAC7+55A+g8y8ruIuip9mq7tFJvNsd0/k1/KziHEA/fo8Ej8PpDH7pLdHdIGDupHPSg9TKQVAMOzw3Y4j3k5mrcG476lTohLGES4KHpXJuvAEj1KylqbmnjobZilhAqb37yBtlgUJKsKsAFekPAdfH2Tsg4ZM9+4vLsKW0MF7qrJjbBwYTtPi5greypUQU9ilyoiZV4jVTXiMolnh32EkoYoP7+R+IeL9rTo9U5gOrRUl6/2uNEgOem7fw==" Feb 13 09:07:46 volumio sudo[24630]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 09:07:46 volumio sudo[24630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:46 volumio sudo[24632]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 09:07:46 volumio sudo[24630]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:46 volumio volumio[24467]: info: Volumio Network Manager: Network status updated: 1 Feb 13 09:07:46 volumio sudo[24632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:46 volumio sudo[24632]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07:46+07:00" level=debug msg="completed challenge" Feb 13 09:07:46 volumio go-librespot[24590]: time="2026-02-13T09:07: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 13 09:07:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:47 volumio volumio[24467]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::pushState Feb 13 09:07:47 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::updateTrackBlock Feb 13 09:07:47 volumio volumio[24467]: info: CorePlayQueue::getTrackBlock Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:07:47 volumio volumio-remote-updater[643]: [2026-02-13 09:07:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770948464 101 Feb 13 09:07:47 volumio volumio[24467]: 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 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:47 volumio volumio[24467]: info: Reloading queue from file Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::setRepeat null single undefined Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::pushState Feb 13 09:07:47 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::setRandom null Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::pushState Feb 13 09:07:47 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:47 volumio volumio[24467]: info: Setting Device type: Raspberry PI Feb 13 09:07:47 volumio volumio[24467]: info: Completed loading Core Plugins Feb 13 09:07:47 volumio volumio[24467]: info: Preparing to generate the ALSA configuration file Feb 13 09:07:47 volumio volumio[24467]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:07:47 volumio volumio[24467]: info: CoreStateMachine::pushState Feb 13 09:07:47 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:47 volumio volumio[24467]: info: Asound.conf file unchanged, so no further update is needed Feb 13 09:07:47 volumio volumio[24467]: info: Output device has changed, restarting MPD Feb 13 09:07:47 volumio volumio[24467]: info: Output device has changed, restarting Shairport Sync Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:47 volumio sudo[24649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 13 09:07:47 volumio sudo[24649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:47 volumio sudo[24651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 09:07:47 volumio sudo[24651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:47 volumio sudo[24653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 09:07:47 volumio sudo[24651]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:47 volumio sudo[24653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:47 volumio volumio[24467]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:07:47 volumio volumio[24467]: info: ___________ START PLUGINS ___________ Feb 13 09:07:47 volumio volumio[24467]: info: ControllerMpd::onStart: Initializing MPD Feb 13 09:07:47 volumio volumio[24467]: info: Creating MPD Configuration file Feb 13 09:07:47 volumio sudo[24649]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:47 volumio volumio[24467]: info: [1770948467830] CoreMusicLibrary::Adding element Media Servers Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:47 volumio volumio[24467]: info: UPNP Browser: Client initialized successfully Feb 13 09:07:47 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 13 09:07:47 volumio sudo[24664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 09:07:47 volumio sudo[24664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:47 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:47 volumio sudo[24662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 09:07:48 volumio sudo[24662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:48 volumio sudo[24662]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:48 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 09:07:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 09:07:48 volumio systemd[1]: mpd.service: Consumed 7.202s CPU time. Feb 13 09:07:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 09:07:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 09:07:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 09:07:48 volumio volumio[24467]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 09:07:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 09:07:48 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 09:07:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 09:07:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 09:07:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 09:07:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 09:07:48 volumio volumio[24467]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:48 volumio volumio[24467]: info: [1770948468206] CoreMusicLibrary::Adding element Last_100 Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:48 volumio volumio[24467]: info: [1770948468226] CoreMusicLibrary::Adding element Webradio Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:07:48 volumio volumio[24467]: info: Initializing BBC Radios Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:48 volumio volumio[24467]: info: Creating Spotify config file Feb 13 09:07:48 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:48 volumio sudo[24678]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 13 09:07:48 volumio sudo[24678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 13 09:07:48 volumio sudo[24678]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:49 volumio volumio[24599]: Starting albumart workers Feb 13 09:07:49 volumio volumio[24600]: Starting albumart workers Feb 13 09:07:49 volumio volumio[24467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:49 volumio volumio[24467]: info: [1770948469682] CoreMusicLibrary::Adding element YouTube Music Feb 13 09:07:49 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:49 volumio volumio[24467]: Cannot find translation for source YouTube Music Feb 13 09:07:49 volumio volumio[24467]: info: Volumio Calling Home Feb 13 09:07:49 volumio volumio[24598]: Starting albumart workers Feb 13 09:07:49 volumio sudo[24695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 13 09:07:49 volumio sudo[24695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 13 09:07:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:50 volumio go-librespot[24699]: go-librespot daemon starting... Feb 13 09:07:50 volumio sudo[24695]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:50 volumio go-librespot[24701]: time="2026-02-13T09:07:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:50 volumio volumio[24467]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 09:07:50 volumio volumio[24467]: info: Discovery: Found device Volumio Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:50 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:50 volumio volumio[24467]: info: MPD Permissions set Feb 13 09:07:50 volumio volumio[24467]: info: MPD Permissions set Feb 13 09:07:50 volumio volumio[24467]: info: Upmpdcli Daemon Started Feb 13 09:07:50 volumio volumio[24467]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 09:07:50 volumio volumio[24467]: info: Discovery: Found device Volumio Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:50 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:50 volumio volumio[24467]: info: Volumio called home Feb 13 09:07:50 volumio volumio[24467]: info: Spotify config file written Feb 13 09:07:50 volumio sudo[24708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 13 09:07:50 volumio sudo[24708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:50 volumio volumio[24467]: 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 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 13 09:07:50 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:07:50 volumio volumio[24467]: info: No need to fix Spotify hosts Feb 13 09:07:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:51 volumio go-librespot[24719]: go-librespot daemon starting... Feb 13 09:07:51 volumio sudo[24708]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+07:00" level=debug msg="app state loaded" Feb 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+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 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+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 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+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 13 09:07:51 volumio go-librespot[24725]: time="2026-02-13T09:07:51+07:00" level=info msg="zeroconf server listening on port 35557" Feb 13 09:07:52 volumio go-librespot[24725]: time="2026-02-13T09:07:52+07:00" level=debug msg="obtained new client token: AAAQ7P60El9DTHfRJxrjaNYRp+RAyxGAS7CuwDPVem4jQqNGKosm1l45grrjUL0bXe4EfkfsecQyUHpyh+8rk+Y1JlAqPfyM5Dpgo2XDwB0efK5uSVswD3Hhqp8W1UlN3ttu6ZuhWrIYGOX+HXilLOzQl/CoYr1cpBFZns/FLmlkSvyTKNonIybMwDi259R+LafGgBfU7xDIdYkvE/F/hUVJwnvtWJ/8N8leyYjCpDHeMLiyi8bvvqI=" Feb 13 09:07:52 volumio go-librespot[24725]: time="2026-02-13T09:07:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:52 volumio volumio[24467]: info: Starting Shairport Sync Feb 13 09:07:52 volumio go-librespot[24725]: time="2026-02-13T09:07:52+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:52 volumio go-librespot[24725]: time="2026-02-13T09:07:52+07:00" level=debug msg="completed challenge" Feb 13 09:07:52 volumio volumio[24467]: info: Starting Shairport Sync Feb 13 09:07:52 volumio volumio[24467]: info: Starting Shairport Sync Feb 13 09:07:52 volumio sudo[24752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:07:52 volumio sudo[24752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:52 volumio go-librespot[24725]: time="2026-02-13T09:07:52+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 13 09:07:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:52 volumio sudo[24756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:07:52 volumio sudo[24754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:07:52 volumio sudo[24756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:52 volumio sudo[24754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:07:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 13 09:07:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 13 09:07:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 09:07:52 volumio systemd[1]: shairport-sync.service: Consumed 2.305s CPU time. Feb 13 09:07:52 volumio volumio[24467]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 09:07:52 volumio volumio[24467]: SPOTIFY: BQDJYgrtH3wmE6hqdQIp8_nfI54pV37840Sk_ILO4ycv58GVRDCUmVmcK1U-Y3quIEJbWBmEtBmCrJiPS_4nvCS6-KiSGFKVaPuHv3fcJeBaqjTHfXcIewur6ziYFK8BehYNMHqmct0HMKa2pHo9QkB9o7HvPQMXyeBicjaG_YxiFyxplXqWW8sSWhQaqz8ji6q_mL3eekTikMH7s84qFN7Nkm0uceAtJXwZ54vmcjNOuSggVmuq0EX226MUyMaN4IpHFCkMnxka1NF_LOu_RdfOzUIliw9CD8eanuZehXkZvRGg1-kfTitw Feb 13 09:07:52 volumio volumio[24467]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 09:07:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 09:07:52 volumio volumio[24467]: info: New Spotify access token = BQDJYgrtH3wmE6hqdQIp8_nfI54pV37840Sk_ILO4ycv58GVRDCUmVmcK1U-Y3quIEJbWBmEtBmCrJiPS_4nvCS6-KiSGFKVaPuHv3fcJeBaqjTHfXcIewur6ziYFK8BehYNMHqmct0HMKa2pHo9QkB9o7HvPQMXyeBicjaG_YxiFyxplXqWW8sSWhQaqz8ji6q_mL3eekTikMH7s84qFN7Nkm0uceAtJXwZ54vmcjNOuSggVmuq0EX226MUyMaN4IpHFCkMnxka1NF_LOu_RdfOzUIliw9CD8eanuZehXkZvRGg1-kfTitw Feb 13 09:07:52 volumio sudo[24756]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:52 volumio sudo[24754]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:52 volumio sudo[24752]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:52 volumio volumio[24467]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 13 09:07:53 volumio volumio[24467]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:53 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:53 volumio volumio[24467]: info: Shairport-Sync Started Feb 13 09:07:53 volumio volumio[24467]: Error adding Membership: Error: addMembership EINVAL Feb 13 09:07:53 volumio volumio[24467]: info: Shairport-Sync Started Feb 13 09:07:53 volumio volumio[24467]: info: Shairport-Sync Started Feb 13 09:07:53 volumio volumio[24467]: 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 13 09:07:53 volumio volumio[24467]: info: Spotify Successfully logged in Feb 13 09:07:53 volumio volumio[24467]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:07:53 volumio volumio[24467]: info: [1770948473476] CoreMusicLibrary::Adding element Spotify Feb 13 09:07:53 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:07:53 volumio volumio[24467]: Cannot find translation for source YouTube Music Feb 13 09:07:53 volumio volumio[24467]: Cannot find translation for source Spotify Feb 13 09:07:53 volumio volumio[24467]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 13 09:07:54 volumio volumio[24467]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:07:54 volumio volumio[24467]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:07:54 volumio volumio[24467]: info: CoreCommandRouter::volumioGetState Feb 13 09:07:54 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:54 volumio volumio[24467]: info: CoreStateMachine::pushState Feb 13 09:07:54 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:07:54 volumio volumio[24467]: info: CoreCommandRouter::volumioPushState Feb 13 09:07:55 volumio volumio[24467]: info: go-librespot daemon successfully initialized Feb 13 09:07:55 volumio mpd[24693]: 2026-02-13T09:07:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 13 09:07:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 13 09:07:55 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 13 09:07:55 volumio sudo[24653]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:55 volumio sudo[24664]: pam_unix(sudo:session): session closed for user root Feb 13 09:07:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:07:55 volumio go-librespot[24795]: go-librespot daemon starting... Feb 13 09:07:55 volumio go-librespot[24797]: time="2026-02-13T09:07:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:07:55 volumio go-librespot[24797]: time="2026-02-13T09:07:55+07:00" level=debug msg="app state loaded" Feb 13 09:07:55 volumio go-librespot[24797]: time="2026-02-13T09:07:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:07:55 volumio volumio[24467]: error: MPD error: The expression evaluated to a falsy value: Feb 13 09:07:55 volumio volumio[24467]: assert.ok(self.idling) Feb 13 09:07:55 volumio volumio[24467]: error: The expression evaluated to a falsy value: Feb 13 09:07:55 volumio volumio[24467]: assert.ok(self.idling) Feb 13 09:07:55 volumio volumio[24467]: error: updateQueue error: null Feb 13 09:07:55 volumio volumio[24467]: info: MPD running with PID24693 Feb 13 09:07:55 volumio volumio[24467]: ,establishing connection Feb 13 09:07:56 volumio volumio[24467]: info: Completed starting Core Plugins Feb 13 09:07:56 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:56 volumio volumio[24467]: info: ----- MyVolumio plugins startup ---- Feb 13 09:07:56 volumio volumio[24467]: info: ------------------------------------------- Feb 13 09:07:56 volumio volumio[24467]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 13 09:07:56 volumio volumio[24467]: error: updateQueue error: null Feb 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+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 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+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 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+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 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+07:00" level=info msg="zeroconf server listening on port 44991" Feb 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+07:00" level=debug msg="obtained new client token: AACatUPQjEuYXrHp36JUuvFTTob7WrFdCfxhNHImksC11sz94V+/TSuFojfDlfySrHhnFqpMpINDJ3LIG37JRufcFC6NIMvmRII+3zO5nA4NSgmLSJZPiucnbxldED1E/BerzjeGEV0zR2D9tUWgH3RjBEhK0HYwrbfKWqffWMsSkXr5pcMcW/pQrhKnLlsrf79TMVFeFMHxmCP9pVfZhpVGsCti9ndRRsz0ZFVzrYZC1KHTB7650GtZ0A==" Feb 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+07:00" level=debug msg="completed keyexchange" Feb 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+07:00" level=debug msg="completed challenge" Feb 13 09:07:56 volumio go-librespot[24797]: time="2026-02-13T09:07:56+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 13 09:07:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:07:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:07:58 volumio volumio[24467]: info: Initializing connection to go-librespot Websocket Feb 13 09:07:58 volumio volumio[24467]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:08:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 13 09:08:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:00 volumio go-librespot[24804]: go-librespot daemon starting... Feb 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+07:00" level=debug msg="app state loaded" Feb 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+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 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+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 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+07:00" level=info msg="zeroconf server listening on port 44403" Feb 13 09:08:00 volumio volumio[24467]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 13 09:08:00 volumio go-librespot[24805]: time="2026-02-13T09:08:00+07:00" level=debug msg="obtained new client token: AACRjuJV6V2Bx1KDaB2NN32BA4yW44sqcLWOq0DI/Oxc/1suALHp4v5fXFh/mi6egENFtOVmmONg8lfffWl9kPt3Q/R5VjFJyKJ2jkRBsOxtYMOFXKNH4rV+of++SUYBxzeq7xce2PKtWexGY1/IFBYpy3mLIkkk5BS7yQNZGUAcSEHKAn+YZ4vNgPTT6YKLwG+kIFfoinqNcaXCAprDRwkVrwlMLo6fhx7lcf2yCM610qsYuFngE9nwSw==" Feb 13 09:08:01 volumio go-librespot[24805]: time="2026-02-13T09:08:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:01 volumio go-librespot[24805]: time="2026-02-13T09:08:01+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:01 volumio go-librespot[24805]: time="2026-02-13T09:08:01+07:00" level=debug msg="completed challenge" Feb 13 09:08:01 volumio go-librespot[24805]: time="2026-02-13T09:08:01+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 13 09:08:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:01 volumio volumio[24467]: info: Initializing connection to go-librespot Websocket Feb 13 09:08:01 volumio volumio[24467]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:08:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 13 09:08:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:04 volumio go-librespot[24813]: go-librespot daemon starting... Feb 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+07:00" level=debug msg="app state loaded" Feb 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:04 volumio volumio[24467]: info: Initializing connection to go-librespot Websocket Feb 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+07:00" level=debug msg="new websocket client" Feb 13 09:08:04 volumio volumio[24467]: info: Connection to go-librespot Websocket established Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin bluetooth to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin multiroom to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin metavolumio to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin cd_controller to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 13 09:08:04 volumio volumio[24467]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+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 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+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 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+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 13 09:08:04 volumio go-librespot[24814]: time="2026-02-13T09:08:04+07:00" level=info msg="zeroconf server listening on port 39471" Feb 13 09:08:05 volumio go-librespot[24814]: time="2026-02-13T09:08:05+07:00" level=debug msg="obtained new client token: AABdcrOk39aynrS/8eSMeNp2eWuhu30b/5ZZwmpOE9Qx2O6R7LJm5lHAvTkfy01BUWA/hev++Df2QHzcFTK1nTu76/f8zwqpar3H6FQF4wqGJYSInbNzeGL1iJkLUcvQs2ZPvSLllCr63T5BGKN+NllJ12kVMGUELarmNa7JXauRv82f3Ee7DAWOPLoISdz/8hRrWBr1RAjs0tZeGlCL3EPE65wryWY8FuQcL6dHHr2aFCfkrwG54q0=" Feb 13 09:08:05 volumio go-librespot[24814]: time="2026-02-13T09:08:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:05 volumio go-librespot[24814]: time="2026-02-13T09:08:05+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:05 volumio go-librespot[24814]: time="2026-02-13T09:08:05+07:00" level=debug msg="completed challenge" Feb 13 09:08:05 volumio go-librespot[24814]: time="2026-02-13T09:08:05+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 13 09:08:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:06 volumio volumio[24467]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 13 09:08:06 volumio volumio[24467]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 13 09:08:06 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:06 volumio volumio[24467]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:06 volumio volumio[24467]: info: Starting MyVolumio Remote Streaming Endpoints Feb 13 09:08:06 volumio volumio[24467]: info: MyVolumio login type: Token Feb 13 09:08:06 volumio volumio[24467]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 13 09:08:06 volumio volumio[24467]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 13 09:08:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 13 09:08:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:08 volumio volumio[24467]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 13 09:08:08 volumio volumio[24467]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 13 09:08:08 volumio volumio[24467]: info: Streaming services startup Feb 13 09:08:08 volumio volumio[24467]: info: Starting Streaming Daemon Feb 13 09:08:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:08 volumio go-librespot[24835]: go-librespot daemon starting... Feb 13 09:08:08 volumio sudo[24837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 13 09:08:08 volumio sudo[24837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:08 volumio volumio[24467]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 13 09:08:08 volumio go-librespot[24839]: time="2026-02-13T09:08:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:08 volumio go-librespot[24839]: time="2026-02-13T09:08:08+07:00" level=debug msg="app state loaded" Feb 13 09:08:08 volumio go-librespot[24839]: time="2026-02-13T09:08:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:08 volumio sudo[24837]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:08 volumio volumio[24467]: info: Getting Spotify volume Feb 13 09:08:08 volumio volumio[24467]: info: Connection to go-librespot Websocket closed Feb 13 09:08:08 volumio volumio[24467]: error: Cannot start Volumio Streaming Daemon Feb 13 09:08:08 volumio volumio[24467]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 13 09:08:08 volumio volumio[24467]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 13 09:08:08 volumio volumio[24467]: 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 13 09:08:09 volumio volumio[24467]: info: CoreCommandRouter::volumioGetState Feb 13 09:08:09 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:09 volumio volumio[24467]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 13 09:08:09 volumio volumio[24467]: SPOTIFY: SPOTIFY VOLUME undefined Feb 13 09:08:09 volumio volumio[24467]: SPOTIFY: VOLUMIO VOLUME 100 Feb 13 09:08:09 volumio volumio[24467]: info: Aligning Spotify Volume to Volumio Volume Feb 13 09:08:09 volumio volumio[24467]: info: CoreCommandRouter::volumioGetState Feb 13 09:08:09 volumio volumio[24467]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:09 volumio volumio[24467]: info: Setting Spotify Volume from Volumio: 100 Feb 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+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 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+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 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+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 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+07:00" level=info msg="zeroconf server listening on port 43973" Feb 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+07:00" level=debug msg="obtained new client token: AAB0+fDhh7QkxgVs20Nsm9bW4nGFvH8aY7q/sdtsgUCoA1oyD7JPY8Dt+rqrnOhOCZIPPw7ArV5sQpARCxo3EWnM5zhXef5zpWUZszvB+/k4y8DWM6QLzhhkYXg0vwBOwMrQNo5NfrE+AdWclKfbrfSwA/nDTIijoBdRjz+JpscZgGj4duEgJsGucPE7B0xvXjXaTuAK/uqhqe7kWA7QHLjEySXWk17RGmmA+ISaYR3ENloNqmxFxoJFhA==" Feb 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08:09+07:00" level=debug msg="completed challenge" Feb 13 09:08:09 volumio go-librespot[24839]: time="2026-02-13T09:08: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 13 09:08:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:09 volumio volumio[24467]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 09:08:09 volumio volumio[24467]: Error: socket hang up Feb 13 09:08:09 volumio volumio[24467]: at connResetException (node:internal/errors:720:14) Feb 13 09:08:09 volumio volumio[24467]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 13 09:08:09 volumio volumio[24467]: at Socket.emit (node:events:526:35) Feb 13 09:08:09 volumio volumio[24467]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 13 09:08:09 volumio volumio[24467]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 13 09:08:09 volumio volumio[24467]: code: 'ECONNRESET', Feb 13 09:08:09 volumio volumio[24467]: response: undefined Feb 13 09:08:09 volumio volumio[24467]: } Feb 13 09:08:09 volumio volumio[24467]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 09:08:11 volumio sudo[24865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 09:07' Feb 13 09:08:11 volumio sudo[24865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:11 volumio sudo[24865]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 13 09:08:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:12 volumio go-librespot[24873]: go-librespot daemon starting... Feb 13 09:08:12 volumio go-librespot[24874]: time="2026-02-13T09:08:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:12 volumio go-librespot[24874]: time="2026-02-13T09:08:12+07:00" level=debug msg="app state loaded" Feb 13 09:08:12 volumio go-librespot[24874]: time="2026-02-13T09:08:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:12 volumio volumio-remote-updater[643]: [2026-02-13 09:08:12] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 13 09:08:12 volumio volumio-remote-updater[643]: [2026-02-13 09:08:12] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 13 09:08:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 13 09:08:12 volumio systemd[1]: volumio.service: Consumed 55.812s CPU time. Feb 13 09:08:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 13 09:08:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 13 09:08:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14499. Feb 13 09:08:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 13 09:08:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 13 09:08:13 volumio systemd[1]: volumio.service: Consumed 55.812s CPU time. Feb 13 09:08:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 13 09:08:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+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 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+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 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+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 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+07:00" level=info msg="zeroconf server listening on port 37537" Feb 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+07:00" level=debug msg="obtained new client token: AAC3IE8L5U+fBWjZ68kznW1+Wi/5CxxINb7O+bBF0JLYTZ3CkWtQzzXdIYoYt+IlfI2/stFsXTxhDrIjLsTREyjljS4WyYwuqJ6KKYupeNExdDC2wYUAJycz7NmwE4Ht26TApziocSykUAZxxA9ECT40FYgAqqHkxAc4j2FUhhGquukbBgKiPuzkvnKwWVqgCGMHklr8zt4jXhHUM4jPV2bdUKTQvwAh8ZTELsJd8AsAouBihh26Hvi6AA==" Feb 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:13 volumio go-librespot[24874]: time="2026-02-13T09:08:13+07:00" level=debug msg="completed challenge" Feb 13 09:08:14 volumio go-librespot[24874]: time="2026-02-13T09:08:14+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 13 09:08:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:16 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:16 volumio volumio[24888]: info: ----- Volumio3 ---- Feb 13 09:08:16 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:16 volumio volumio[24888]: info: ----- System startup ---- Feb 13 09:08:16 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 13 09:08:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:17 volumio go-librespot[24910]: go-librespot daemon starting... Feb 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+07:00" level=debug msg="app state loaded" Feb 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+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 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+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 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+07:00" level=info msg="zeroconf server listening on port 42803" Feb 13 09:08:17 volumio volumio-remote-updater[643]: [2026-02-13 09:08:17] [connect] Successful connection Feb 13 09:08:17 volumio go-librespot[24911]: time="2026-02-13T09:08:17+07:00" level=debug msg="obtained new client token: AAD8km+coDUl6kobt7wKChYrIaQoPoBx+9pN6SI31lIZkgfkF8iztGOjfApfl+I7VjIhPsTxhN3MkXno7yU95zvTZ7opoDfU/2BHmi4CW2f4rdc47F/MA0mncaAwD1GDy3JNsMVMuU7Ld8eIT4tqVu7jSMRKQKJj1fwXL6c/jAFDHeqvzjLhw2ZkgUvmyExn3UL/dfvYOvSyJHd2TKkvFGp2J+F78f7ijZRe7g4g14JeVCEYGfDFSjq1kg==" Feb 13 09:08:18 volumio go-librespot[24911]: time="2026-02-13T09:08:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:18 volumio go-librespot[24911]: time="2026-02-13T09:08:18+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:18 volumio go-librespot[24911]: time="2026-02-13T09:08:18+07:00" level=debug msg="completed challenge" Feb 13 09:08:18 volumio go-librespot[24911]: time="2026-02-13T09:08:18+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 13 09:08:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:18 volumio volumio[24888]: info: MYVOLUMIO Environment detected Feb 13 09:08:18 volumio volumio[24888]: info: Plugin folders cleanup Feb 13 09:08:18 volumio volumio[24888]: info: Scanning into folder /volumio/app/plugins/ Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category audio_interface Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category miscellanea Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category music_service Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category plugins.json Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category system_controller Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category user_interface Feb 13 09:08:18 volumio volumio[24888]: info: Scanning into folder /data/plugins/ Feb 13 09:08:18 volumio volumio[24888]: info: Scanning category music_service Feb 13 09:08:18 volumio volumio[24888]: info: Plugin folders cleanup completed Feb 13 09:08:18 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:18 volumio volumio[24888]: info: ----- Core plugins startup ---- Feb 13 09:08:18 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:18 volumio volumio[24888]: info: Loading plugins from folder /volumio/app/plugins/ Feb 13 09:08:18 volumio volumio[24888]: info: Adding plugin upnp to MyMusic Plugins Feb 13 09:08:18 volumio volumio[24888]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 13 09:08:18 volumio volumio[24888]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 13 09:08:18 volumio volumio[24888]: info: Loading plugins from folder /data/plugins/ Feb 13 09:08:18 volumio volumio[24888]: info: Loading plugin "system"... Feb 13 09:08:18 volumio volumio[24888]: info: Loading plugin "appearance"... Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "network"... Feb 13 09:08:20 volumio volumio[24888]: info: Refreshing Cached IP Addresses Feb 13 09:08:20 volumio sudo[24925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 09:08:20 volumio sudo[24925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:20 volumio sudo[24925]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:20 volumio sudo[24927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "services"... Feb 13 09:08:20 volumio sudo[24927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:20 volumio sudo[24927]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "alsa_controller"... Feb 13 09:08:20 volumio sudo[24939]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 13 09:08:20 volumio sudo[24939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:20 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "wizard"... Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "networkfs"... Feb 13 09:08:20 volumio volumio[24888]: info: Starting Udev Watcher for removable devices Feb 13 09:08:20 volumio volumio[24888]: info: Ignoring mount for partition: boot Feb 13 09:08:20 volumio volumio[24888]: info: Ignoring mount for partition: volumio Feb 13 09:08:20 volumio volumio[24888]: info: Ignoring mount for partition: volumio_data Feb 13 09:08:20 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "volumio_command_line_client"... Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "upnp"... Feb 13 09:08:20 volumio volumio[24888]: info: [1770948500875] Starting Upmpd Daemon Feb 13 09:08:20 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "my_music"... Feb 13 09:08:20 volumio volumio[24888]: info: Loading plugin "mpd"... Feb 13 09:08:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 13 09:08:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:21 volumio go-librespot[24958]: go-librespot daemon starting... Feb 13 09:08:21 volumio go-librespot[24959]: time="2026-02-13T09:08:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:21 volumio go-librespot[24959]: time="2026-02-13T09:08:21+07:00" level=debug msg="app state loaded" Feb 13 09:08:21 volumio go-librespot[24959]: time="2026-02-13T09:08:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:21 volumio volumio[24888]: info: Loading plugin "upnp_browser"... Feb 13 09:08:21 volumio go-librespot[24959]: time="2026-02-13T09:08: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 13 09:08:21 volumio go-librespot[24959]: time="2026-02-13T09:08: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 13 09:08:21 volumio go-librespot[24959]: time="2026-02-13T09:08: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 13 09:08:22 volumio go-librespot[24959]: time="2026-02-13T09:08:22+07:00" level=info msg="zeroconf server listening on port 33395" Feb 13 09:08:22 volumio go-librespot[24959]: time="2026-02-13T09:08:22+07:00" level=debug msg="obtained new client token: AABAuai/4RjHnNbTiLRukJr2wf9SA4pZk5TI91qM5Ov+U3ucmKD9gbddRE1zrW8+RL7ZrL/zGeflKyP/Bp35b8onR4WKm7BDdP3TfwhLRcsYbtLOrWormxTLbK7qbWyN7SqJiEDvQ8+0uwF4yNlHtC0KY6tbHaxfo/xgD9hgeAGUxTBebqiBkWgE5JR7LXBZFY0uaKh9ybRPJFtFBRxav8ufdZK26Wiv7mRfQ11nTwf4GEB6YMv5WK4=" Feb 13 09:08:22 volumio go-librespot[24959]: time="2026-02-13T09:08:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:22 volumio go-librespot[24959]: time="2026-02-13T09:08:22+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:22 volumio go-librespot[24959]: time="2026-02-13T09:08:22+07:00" level=debug msg="completed challenge" Feb 13 09:08:22 volumio go-librespot[24959]: time="2026-02-13T09:08:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:08:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:23 volumio sudo[24939]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:24 volumio volumio[24888]: info: Starting UPNP Browser Feb 13 09:08:24 volumio volumio[24888]: info: Loading plugin "alarm-clock"... Feb 13 09:08:24 volumio volumio[24888]: info: Loading plugin "airplay_emulation"... Feb 13 09:08:24 volumio volumio[24888]: info: Starting Shairport Sync Feb 13 09:08:24 volumio volumio[24888]: info: Loading plugin "last_100"... Feb 13 09:08:24 volumio volumio[24888]: info: Loading plugin "webradio"... Feb 13 09:08:25 volumio volumio[24888]: info: Loading plugin "i2s_dacs"... Feb 13 09:08:25 volumio volumio[24888]: info: Loading plugin "volumiodiscovery"... Feb 13 09:08:25 volumio volumio[24888]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 09:08:25 volumio volumio[24888]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:08:25 volumio volumio[24888]: *** WARNING *** For more information see Feb 13 09:08:25 volumio volumio[24888]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 09:08:25 volumio volumio[24888]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:08:25 volumio volumio[24888]: *** WARNING *** For more information see Feb 13 09:08:25 volumio node[24888]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 13 09:08:25 volumio node[24888]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:08:25 volumio node[24888]: *** WARNING *** For more information see Feb 13 09:08:25 volumio node[24888]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 13 09:08:25 volumio node[24888]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 13 09:08:25 volumio node[24888]: *** WARNING *** For more information see Feb 13 09:08:25 volumio volumio[24888]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 13 09:08:25 volumio volumio[24888]: info: Discovery: Started advertising with name: Volumio Feb 13 09:08:25 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 13 09:08:25 volumio volumio[24888]: info: Loading plugin "spop"... Feb 13 09:08:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 13 09:08:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:25 volumio go-librespot[24968]: go-librespot daemon starting... Feb 13 09:08:25 volumio go-librespot[24969]: time="2026-02-13T09:08:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:25 volumio go-librespot[24969]: time="2026-02-13T09:08:25+07:00" level=debug msg="app state loaded" Feb 13 09:08:25 volumio go-librespot[24969]: time="2026-02-13T09:08:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+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 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+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 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+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 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+07:00" level=info msg="zeroconf server listening on port 43277" Feb 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+07:00" level=debug msg="obtained new client token: AADlrOquNTz0ZNBFCyzhBSgbhGgsYQAcdUAtBRg3X8G/BZmUWEauLSBKkJw9tUpOW5/oRvTOT7SnZ+pgbmUgrSJWOUqRPxJVUW2HmIV9zJ/rQAb/pMbN8pifZWX0scoqYLabGfMcg6S5KD3LwZxCP+f2vSvBeUuo17lFqwCCEwNQR33ekBu3ChQ9Ckr3T+vj/4ys3gsFVERKmYCVOKy4swNnthqlQ0oqVADUTd6oN2N9JmvWU1tYbRaNKA==" Feb 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08:26+07:00" level=debug msg="completed challenge" Feb 13 09:08:26 volumio go-librespot[24969]: time="2026-02-13T09:08: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 13 09:08:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:27 volumio volumio[24888]: info: Loading plugin "ytcr"... Feb 13 09:08:29 volumio volumio[24888]: info: Loading plugin "ytmusic"... Feb 13 09:08:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 13 09:08:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:30 volumio go-librespot[24977]: go-librespot daemon starting... Feb 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+07:00" level=debug msg="app state loaded" Feb 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:30 volumio volumio-remote-updater[643]: [2026-02-13 09:08:30] [connect] Successful connection Feb 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+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 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+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 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+07:00" level=info msg="zeroconf server listening on port 46359" Feb 13 09:08:30 volumio volumio[24888]: info: Loading plugin "outputs"... Feb 13 09:08:30 volumio volumio[24888]: info: Loading plugin "albumart"... Feb 13 09:08:30 volumio volumio[24888]: info: Plugin example_plugin is not enabled Feb 13 09:08:30 volumio volumio[24888]: info: Loading plugin "inputs"... Feb 13 09:08:30 volumio volumio[24888]: info: Loading plugin "updater_comm"... Feb 13 09:08:30 volumio go-librespot[24978]: time="2026-02-13T09:08:30+07:00" level=debug msg="obtained new client token: AACTrN/c3G/tElVaLAD2QzHUsfs8bqjCuzxr/GzrxBfEKYszlk5mj/hyXWRvFq4qBrYTAUK8z1VoaEhxNcmEFVNuiCJzDqPsAR2eX+cJKWE+rEVMfgUc5qkyQVec3OAVrFRThGs1jcG3pw8Pbut/PngMTdqj/FBieHpGD7jcRvIKdZjTeYlHJ4H6VAVWJxg451izoao5+FB/0pnvWppELr0hvJiBR/VAsMi1TdDHF9nTkctFSShXOXWNQA==" Feb 13 09:08:31 volumio go-librespot[24978]: time="2026-02-13T09:08:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:31 volumio volumio[24888]: info: Plugin mpdemulation is not enabled Feb 13 09:08:31 volumio volumio[24888]: info: Loading plugin "rest_api"... Feb 13 09:08:31 volumio volumio[24888]: info: Loading plugin "websocket"... Feb 13 09:08:31 volumio go-librespot[24978]: time="2026-02-13T09:08:31+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:31 volumio go-librespot[24978]: time="2026-02-13T09:08:31+07:00" level=debug msg="completed challenge" Feb 13 09:08:31 volumio volumio[24888]: info: Starting Socket.io Server version 1.7.4 Feb 13 09:08:31 volumio volumio[24888]: info: Loading plugin "RoonBridge"... Feb 13 09:08:31 volumio go-librespot[24978]: time="2026-02-13T09:08:31+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 13 09:08:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:31 volumio volumio[24888]: info: Applying required configuration parameters for plugin RoonBridge Feb 13 09:08:31 volumio volumio[24888]: info: Loading i18n strings for locale en Feb 13 09:08:31 volumio volumio[24888]: Updating browse sources language Feb 13 09:08:31 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:08:31 volumio volumio[24999]: Forking 3 albumart workers Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::initPlayerControls Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: Express server listening on port 3000 Feb 13 09:08:32 volumio volumio[24888]: [Metrics] WebUI: 16s 232.83ms Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::resetVolumioState Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::getcurrentVolume Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:08:32 volumio sudo[25043]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 13 09:08:32 volumio sudo[25043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:32 volumio sudo[25046]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 13 09:08:32 volumio sudo[25046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:32 volumio sudo[25043]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:32 volumio volumio[24888]: info: Volumio Network Manager: Network status updated: 1 Feb 13 09:08:32 volumio sudo[25046]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:32 volumio volumio[24888]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::pushState Feb 13 09:08:32 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::volumioPushState Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::updateTrackBlock Feb 13 09:08:32 volumio volumio[24888]: info: CorePlayQueue::getTrackBlock Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:08:32 volumio volumio-remote-updater[643]: [2026-02-13 09:08:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770948510 101 Feb 13 09:08:32 volumio volumio[24888]: 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 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:32 volumio volumio[24888]: info: Reloading queue from file Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::setRepeat null single undefined Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::pushState Feb 13 09:08:32 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::volumioPushState Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::setRandom null Feb 13 09:08:32 volumio volumio[24888]: info: CoreStateMachine::pushState Feb 13 09:08:32 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:32 volumio volumio[24888]: info: CoreCommandRouter::volumioPushState Feb 13 09:08:32 volumio volumio[24888]: info: Setting Device type: Raspberry PI Feb 13 09:08:33 volumio volumio[24888]: info: Completed loading Core Plugins Feb 13 09:08:33 volumio volumio[24888]: info: Preparing to generate the ALSA configuration file Feb 13 09:08:33 volumio volumio[24888]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:08:33 volumio volumio[24888]: info: CoreStateMachine::pushState Feb 13 09:08:33 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::volumioPushState Feb 13 09:08:33 volumio volumio[24888]: info: Asound.conf file unchanged, so no further update is needed Feb 13 09:08:33 volumio volumio[24888]: info: Output device has changed, restarting MPD Feb 13 09:08:33 volumio volumio[24888]: info: Output device has changed, restarting Shairport Sync Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:33 volumio sudo[25061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 13 09:08:33 volumio sudo[25061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:33 volumio sudo[25065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 09:08:33 volumio sudo[25063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 09:08:33 volumio sudo[25065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:33 volumio sudo[25063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:33 volumio volumio[24888]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:08:33 volumio volumio[24888]: info: ___________ START PLUGINS ___________ Feb 13 09:08:33 volumio sudo[25063]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:33 volumio volumio[24888]: info: ControllerMpd::onStart: Initializing MPD Feb 13 09:08:33 volumio volumio[24888]: info: Creating MPD Configuration file Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:08:33 volumio volumio[24888]: info: [1770948513395] CoreMusicLibrary::Adding element Media Servers Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:08:33 volumio sudo[25074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 13 09:08:33 volumio sudo[25074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 13 09:08:33 volumio volumio[24888]: info: UPNP Browser: Client initialized successfully Feb 13 09:08:33 volumio sudo[25061]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:33 volumio sudo[25074]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:33 volumio sudo[25076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 13 09:08:33 volumio sudo[25076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 09:08:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 09:08:33 volumio systemd[1]: mpd.service: Consumed 7.056s CPU time. Feb 13 09:08:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 09:08:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 09:08:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 09:08:33 volumio volumio[24888]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 09:08:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 09:08:33 volumio volumio[24888]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:08:33 volumio volumio[24888]: info: [1770948513741] CoreMusicLibrary::Adding element Last_100 Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:08:33 volumio volumio[24888]: info: [1770948513764] CoreMusicLibrary::Adding element Webradio Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:08:33 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:08:33 volumio volumio[24888]: info: Initializing BBC Radios Feb 13 09:08:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 13 09:08:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 13 09:08:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 13 09:08:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 13 09:08:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 13 09:08:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 13 09:08:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 13 09:08:34 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 13 09:08:34 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:34 volumio volumio[24888]: info: Creating Spotify config file Feb 13 09:08:34 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 13 09:08:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:34 volumio go-librespot[25104]: go-librespot daemon starting... Feb 13 09:08:34 volumio sudo[25100]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 13 09:08:34 volumio sudo[25100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 13 09:08:34 volumio sudo[25100]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:34 volumio go-librespot[25105]: time="2026-02-13T09:08:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:34 volumio volumio[25010]: Starting albumart workers Feb 13 09:08:35 volumio go-librespot[25105]: time="2026-02-13T09:08:35+07:00" level=info msg="zeroconf server listening on port 44775" Feb 13 09:08:35 volumio volumio[25009]: Starting albumart workers Feb 13 09:08:35 volumio volumio[25011]: Starting albumart workers Feb 13 09:08:35 volumio volumio[24888]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:08:35 volumio volumio[24888]: info: [1770948515650] CoreMusicLibrary::Adding element YouTube Music Feb 13 09:08:35 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:08:35 volumio volumio[24888]: Cannot find translation for source YouTube Music Feb 13 09:08:35 volumio volumio[24888]: info: Volumio Calling Home Feb 13 09:08:35 volumio sudo[25117]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 13 09:08:35 volumio sudo[25117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:36 volumio sudo[25117]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:36 volumio volumio[24888]: info: MPD Permissions set Feb 13 09:08:36 volumio volumio[24888]: info: MPD Permissions set Feb 13 09:08:36 volumio volumio[24888]: info: Upmpdcli Daemon Started Feb 13 09:08:36 volumio volumio[24888]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 09:08:36 volumio volumio[24888]: info: Discovery: Found device Volumio Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::volumioGetState Feb 13 09:08:36 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:36 volumio volumio[24888]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 13 09:08:36 volumio volumio[24888]: info: Discovery: Found device Volumio Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::volumioGetState Feb 13 09:08:36 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:36 volumio volumio[24888]: info: Volumio called home Feb 13 09:08:36 volumio volumio[24888]: info: Spotify config file written Feb 13 09:08:36 volumio sudo[25122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 13 09:08:36 volumio volumio[24888]: 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 13 09:08:36 volumio sudo[25122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 13 09:08:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 13 09:08:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:36 volumio go-librespot[25129]: go-librespot daemon starting... Feb 13 09:08:37 volumio sudo[25122]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:37 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:37 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 13 09:08:37 volumio volumio[24888]: info: No need to fix Spotify hosts Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=debug msg="app state loaded" Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 13 09:08:37 volumio go-librespot[25131]: time="2026-02-13T09:08:37+07:00" level=info msg="zeroconf server listening on port 36597" Feb 13 09:08:38 volumio go-librespot[25131]: time="2026-02-13T09:08:38+07:00" level=debug msg="obtained new client token: AACXljs7AgHm5pqQIHMghJb3A3vXPxBwqCIqp9K7/uUc6pJNIBJ0jAJ4EKaAJMu729/tD1lqwgGwG1zELd+lcNILXjGR65QRjhkD4C1f2UBTb8A3QahdaZuQrARKkjcZpeGxBSqM9KxJ0pU+tjrZYEBUO10687/FDuYySA6WI35FnXCA44SVjHPoyTx6BSbKP4rvaUPPAu4tFIfh426CMG7NZY67ec8zlVOuPKFNe4FGyQ4VWuw3MTcbTQ==" Feb 13 09:08:38 volumio go-librespot[25131]: time="2026-02-13T09:08:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:38 volumio volumio[24888]: info: Starting Shairport Sync Feb 13 09:08:38 volumio volumio[24888]: info: Starting Shairport Sync Feb 13 09:08:38 volumio volumio[24888]: info: Starting Shairport Sync Feb 13 09:08:38 volumio go-librespot[25131]: time="2026-02-13T09:08:38+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:38 volumio go-librespot[25131]: time="2026-02-13T09:08:38+07:00" level=debug msg="completed challenge" Feb 13 09:08:38 volumio sudo[25164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:08:38 volumio sudo[25162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:08:38 volumio sudo[25164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:38 volumio sudo[25162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:38 volumio sudo[25166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 13 09:08:38 volumio sudo[25166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:38 volumio go-librespot[25131]: time="2026-02-13T09:08:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 13 09:08:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:38 volumio volumio[24888]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 09:08:38 volumio volumio[24888]: SPOTIFY: BQBW8cVxy0XW9sbxDIzP3UpI87mFHJv0ihvlMqAT6wuPAbo4JFRp8fU8ktRikRtmw9KvS2n3QsWFonE60RPJXurly6nJU9jRQVLup4ZloONlo6zyC2270zS-zEL8hlk5wrIzv_SJ1qffzjLNZSgbXJOF1Yi2nNM1c_QoumT5YE35Y4s1pHzhrR5QH0v3ZAYVOKfjl5x0vRe_PliZwiQJt9ajk_nkM8_x2HUIBcJM2vMMFo8jIkuyPtZUlncoK5hqOHUb88-RIvxuSjrdzwakVku9K8UsYoxASerNCq8PRfTGzRSkYnxAh18O Feb 13 09:08:38 volumio volumio[24888]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 13 09:08:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 13 09:08:38 volumio volumio[24888]: info: New Spotify access token = BQBW8cVxy0XW9sbxDIzP3UpI87mFHJv0ihvlMqAT6wuPAbo4JFRp8fU8ktRikRtmw9KvS2n3QsWFonE60RPJXurly6nJU9jRQVLup4ZloONlo6zyC2270zS-zEL8hlk5wrIzv_SJ1qffzjLNZSgbXJOF1Yi2nNM1c_QoumT5YE35Y4s1pHzhrR5QH0v3ZAYVOKfjl5x0vRe_PliZwiQJt9ajk_nkM8_x2HUIBcJM2vMMFo8jIkuyPtZUlncoK5hqOHUb88-RIvxuSjrdzwakVku9K8UsYoxASerNCq8PRfTGzRSkYnxAh18O Feb 13 09:08:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 13 09:08:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 09:08:38 volumio systemd[1]: shairport-sync.service: Consumed 2.343s CPU time. Feb 13 09:08:38 volumio volumio[24888]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 13 09:08:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 13 09:08:38 volumio sudo[25166]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:38 volumio sudo[25164]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:38 volumio sudo[25162]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:38 volumio volumio[24888]: info: Shairport-Sync Started Feb 13 09:08:38 volumio volumio[24888]: Error adding Membership: Error: addMembership EINVAL Feb 13 09:08:38 volumio volumio[24888]: info: Shairport-Sync Started Feb 13 09:08:38 volumio volumio[24888]: info: Shairport-Sync Started Feb 13 09:08:38 volumio volumio[24888]: info: CoreCommandRouter::volumioGetState Feb 13 09:08:38 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:39 volumio volumio[24888]: 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 13 09:08:39 volumio volumio[24888]: info: Spotify Successfully logged in Feb 13 09:08:39 volumio volumio[24888]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 13 09:08:39 volumio volumio[24888]: info: [1770948519065] CoreMusicLibrary::Adding element Spotify Feb 13 09:08:39 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 13 09:08:39 volumio volumio[24888]: Cannot find translation for source YouTube Music Feb 13 09:08:39 volumio volumio[24888]: Cannot find translation for source Spotify Feb 13 09:08:39 volumio volumio[24888]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 13 09:08:39 volumio volumio[24888]: info: CoreCommandRouter::volumioRetrievevolume Feb 13 09:08:39 volumio volumio[24888]: info: VolumeController:: Volume=100 Mute =false Feb 13 09:08:39 volumio volumio[24888]: info: CoreCommandRouter::volumioGetState Feb 13 09:08:39 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:39 volumio volumio[24888]: info: CoreStateMachine::pushState Feb 13 09:08:39 volumio volumio[24888]: info: CorePlayQueue::getTrack 0 Feb 13 09:08:39 volumio volumio[24888]: info: CoreCommandRouter::volumioPushState Feb 13 09:08:41 volumio volumio[24888]: info: go-librespot daemon successfully initialized Feb 13 09:08:41 volumio mpd[25112]: 2026-02-13T09:08:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 13 09:08:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 13 09:08:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 13 09:08:41 volumio sudo[25076]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:41 volumio sudo[25065]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:41 volumio go-librespot[25205]: go-librespot daemon starting... Feb 13 09:08:41 volumio go-librespot[25206]: time="2026-02-13T09:08:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:41 volumio go-librespot[25206]: time="2026-02-13T09:08:41+07:00" level=debug msg="app state loaded" Feb 13 09:08:41 volumio go-librespot[25206]: time="2026-02-13T09:08:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:41 volumio volumio[24888]: error: MPD error: The expression evaluated to a falsy value: Feb 13 09:08:41 volumio volumio[24888]: assert.ok(self.idling) Feb 13 09:08:41 volumio volumio[24888]: error: The expression evaluated to a falsy value: Feb 13 09:08:41 volumio volumio[24888]: assert.ok(self.idling) Feb 13 09:08:41 volumio volumio[24888]: error: updateQueue error: null Feb 13 09:08:41 volumio volumio[24888]: info: MPD running with PID25112 Feb 13 09:08:41 volumio volumio[24888]: ,establishing connection Feb 13 09:08:41 volumio volumio[24888]: info: Completed starting Core Plugins Feb 13 09:08:41 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:41 volumio volumio[24888]: info: ----- MyVolumio plugins startup ---- Feb 13 09:08:41 volumio volumio[24888]: info: ------------------------------------------- Feb 13 09:08:41 volumio volumio[24888]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 13 09:08:41 volumio volumio[24888]: error: updateQueue error: null Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=info msg="zeroconf server listening on port 37411" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="obtained new client token: AABBJWbT+WJhuyVRgRgy67TubxYB9XlKabUcSPaBCeE4VC1mgDbrOPc6utwJYHfGsupbqH1YrC2knVyqzR9Hrlk/da51dYjM4g0o+QluAF1r/1t6Y1Q3xPWt+eb1AkvhjcKuzQCdLO7MVKgmQ9CUITQpEKF+H55/RlIJO4k0LL+0ACqCUuzYJCApnhFXlmU5tC8fIMa9ubml7ziI/7XkB4bDrOqYFHAr77ilUZ57IiIKS5Cy+Ro3Z2dD/g==" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08:42+07:00" level=debug msg="completed challenge" Feb 13 09:08:42 volumio go-librespot[25206]: time="2026-02-13T09:08: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 13 09:08:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:44 volumio volumio[24888]: info: Initializing connection to go-librespot Websocket Feb 13 09:08:44 volumio volumio[24888]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:08:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 13 09:08:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:45 volumio go-librespot[25215]: go-librespot daemon starting... Feb 13 09:08:45 volumio go-librespot[25216]: time="2026-02-13T09:08:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:45 volumio go-librespot[25216]: time="2026-02-13T09:08:45+07:00" level=debug msg="app state loaded" Feb 13 09:08:45 volumio go-librespot[25216]: time="2026-02-13T09:08:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=info msg="zeroconf server listening on port 35685" Feb 13 09:08:46 volumio volumio[24888]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="obtained new client token: AADEevr/mWvCBHW/hXmeq4t6UEHqtrESz3rudwhl7VzAx7zaD0XRj2eGEo7Ooq0oLvZ9FkLPfLxg108ekNlKlFK3FZNx1O7y00LQGVJqntj1NvAIW0H45C7zs8PVXJQaz3IHsLoJiWwrSBUR+GjIOZjK2NTsr5Q9dKJhyHrnYQQOFzpMQ2jfWclYuaYlNi+WhnqxWIhPL9Tmbxe+z5vAHCUTCzaX2JRYW51J4/EeszA34lSSsBMxJ9Wv4w==" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08:46+07:00" level=debug msg="completed challenge" Feb 13 09:08:46 volumio go-librespot[25216]: time="2026-02-13T09:08: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 13 09:08:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:47 volumio volumio[24888]: info: Initializing connection to go-librespot Websocket Feb 13 09:08:47 volumio volumio[24888]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:08:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 13 09:08:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:50 volumio go-librespot[25223]: go-librespot daemon starting... Feb 13 09:08:50 volumio volumio[24888]: info: Initializing connection to go-librespot Websocket Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=debug msg="app state loaded" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:50 volumio volumio[24888]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin bluetooth to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin multiroom to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin metavolumio to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin cd_controller to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 13 09:08:50 volumio volumio[24888]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=info msg="zeroconf server listening on port 46499" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=debug msg="obtained new client token: AACfPAYacoupE2Kdu+Or2jff+PhDM2951ef9elOuhf8Ahqqjen5j2aGtwM3mt57K8+v16PqJCt163Ev3mRyyx7bHdUiGMrKpSR3DcxsTSWkiM0nZiBWwcqB6F0RSUTGoMw/hQV1HvEjWvP2MX2nf20tkTJW5kMpPeuaTN3VFT20rih5DSIGENNsxKCBggTvakvxoPwOE6MIufGPYi0cvAqO+uhnCMAxlFXnyHgzH+GJxYQht5N1oA9r+zg==" Feb 13 09:08:50 volumio go-librespot[25224]: time="2026-02-13T09:08:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:51 volumio go-librespot[25224]: time="2026-02-13T09:08:51+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:51 volumio go-librespot[25224]: time="2026-02-13T09:08:51+07:00" level=debug msg="completed challenge" Feb 13 09:08:51 volumio go-librespot[25224]: time="2026-02-13T09:08:51+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 13 09:08:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:52 volumio volumio[24888]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 13 09:08:52 volumio volumio[24888]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 13 09:08:52 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:52 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:52 volumio volumio[24888]: info: Starting MyVolumio Remote Streaming Endpoints Feb 13 09:08:52 volumio volumio[24888]: info: MyVolumio login type: Token Feb 13 09:08:52 volumio volumio[24888]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 13 09:08:52 volumio volumio[24888]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 13 09:08:54 volumio volumio[24888]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 13 09:08:54 volumio volumio[24888]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 13 09:08:54 volumio volumio[24888]: info: Streaming services startup Feb 13 09:08:54 volumio volumio[24888]: info: Starting Streaming Daemon Feb 13 09:08:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 13 09:08:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:54 volumio sudo[25246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 13 09:08:54 volumio volumio[24888]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 13 09:08:54 volumio sudo[25246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:54 volumio go-librespot[25249]: go-librespot daemon starting... Feb 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+07:00" level=debug msg="app state loaded" Feb 13 09:08:54 volumio sudo[25246]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:54 volumio volumio[24888]: info: Initializing connection to go-librespot Websocket Feb 13 09:08:54 volumio volumio[24888]: error: Cannot start Volumio Streaming Daemon Feb 13 09:08:54 volumio volumio[24888]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 13 09:08:54 volumio volumio[24888]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+07:00" level=debug msg="new websocket client" Feb 13 09:08:54 volumio volumio[24888]: info: Connection to go-librespot Websocket established Feb 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+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 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+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 13 09:08:54 volumio go-librespot[25253]: time="2026-02-13T09:08:54+07:00" level=info msg="zeroconf server listening on port 33363" Feb 13 09:08:55 volumio go-librespot[25253]: time="2026-02-13T09:08:55+07:00" level=debug msg="obtained new client token: AACNGDw14Um7QJiT9o4IxHoIrNhA7PVqWa6OwyDXhkQ2YSK4F0VtgQH/1S3N0dTEaV6ehVEwzHJdIBm7YQNNS5hoojFFxjHqvre2T1Xzb+sFjoLatQ2xlqQywbi71dii67WkJymfSoiM6z0yxNQTDTu6z6QIeZ8ZnFcWg1z1wTN/hCVOGyya6F9ZRndZVaiyd+aApLPlSkdPmVkcu7C/AXd8oza5e5IM7TYUbPJAMfybSgIDBL4NYQk=" Feb 13 09:08:55 volumio go-librespot[25253]: time="2026-02-13T09:08:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 13 09:08:55 volumio go-librespot[25253]: time="2026-02-13T09:08:55+07:00" level=debug msg="completed keyexchange" Feb 13 09:08:55 volumio go-librespot[25253]: time="2026-02-13T09:08:55+07:00" level=debug msg="completed challenge" Feb 13 09:08:55 volumio go-librespot[25253]: time="2026-02-13T09:08:55+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 13 09:08:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 13 09:08:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 13 09:08:55 volumio volumio[24888]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 13 09:08:55 volumio volumio[24888]: info: Connection to go-librespot Websocket closed Feb 13 09:08:56 volumio volumio[24888]: info: MyVolumio token set successfully Feb 13 09:08:56 volumio volumio[24888]: info: MYVOLUMIO: Adding device Feb 13 09:08:56 volumio volumio[24888]: info: MYVOLUMIO: Evaluating Server Feb 13 09:08:56 volumio volumio[24888]: info: MyVolumio status changed Feb 13 09:08:56 volumio volumio[24888]: info: Streaming services startup Feb 13 09:08:56 volumio volumio[24888]: info: Starting Streaming Daemon Feb 13 09:08:56 volumio volumio[24888]: info: Removing browser output: myVolumio user plan is not superstar Feb 13 09:08:56 volumio volumio[24888]: info: Removing audio output: Feb 13 09:08:56 volumio volumio[24888]: info: Stoppping Tunnel 1 Feb 13 09:08:56 volumio sudo[25283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 13 09:08:56 volumio sudo[25283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:56 volumio sudo[25283]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:56 volumio sudo[25286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 13 09:08:56 volumio sudo[25286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:56 volumio volumio[24888]: error: Cannot start Volumio Streaming Daemon Feb 13 09:08:56 volumio volumio[24888]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 13 09:08:56 volumio volumio[24888]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 13 09:08:56 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:56 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:56 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:56 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:57 volumio volumio[24888]: info: Setting Geolocation for MyVolumio to as1 Feb 13 09:08:57 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:57 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:57 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:57 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:57 volumio volumio[24888]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 13 09:08:57 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:57 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 13 09:08:57 volumio sudo[25286]: pam_unix(sudo:session): session closed for user root Feb 13 09:08:57 volumio volumio[24888]: info: Remote SSH Stopped Feb 13 09:08:57 volumio volumio[24888]: info: Getting Spotify volume Feb 13 09:08:57 volumio volumio[24888]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 09:08:57 volumio volumio[24888]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 13 09:08:57 volumio volumio[24888]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 13 09:08:57 volumio volumio[24888]: errno: -111, Feb 13 09:08:57 volumio volumio[24888]: code: 'ECONNREFUSED', Feb 13 09:08:57 volumio volumio[24888]: syscall: 'connect', Feb 13 09:08:57 volumio volumio[24888]: address: '127.0.0.1', Feb 13 09:08:57 volumio volumio[24888]: port: 9879, Feb 13 09:08:57 volumio volumio[24888]: response: undefined Feb 13 09:08:57 volumio volumio[24888]: } Feb 13 09:08:57 volumio volumio[24888]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 13 09:08:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 13 09:08:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 13 09:08:58 volumio go-librespot[25300]: go-librespot daemon starting... Feb 13 09:08:58 volumio go-librespot[25301]: time="2026-02-13T09:08:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 13 09:08:58 volumio go-librespot[25301]: time="2026-02-13T09:08:58+07:00" level=debug msg="app state loaded" Feb 13 09:08:58 volumio go-librespot[25301]: time="2026-02-13T09:08:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 13 09:08:59 volumio sudo[25311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 09:07' Feb 13 09:08:59 volumio sudo[25311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 13 09:08:59 volumio go-librespot[25301]: time="2026-02-13T09:08:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 13 09:08:59 volumio go-librespot[25301]: time="2026-02-13T09:08:59+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 13 09:08:59 volumio go-librespot[25301]: time="2026-02-13T09:08:59+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 13 09:08:59 volumio go-librespot[25301]: time="2026-02-13T09:08:59+07:00" level=info msg="zeroconf server listening on port 40027" Feb 13 09:08:59 volumio go-librespot[25301]: time="2026-02-13T09:08:59+07:00" level=debug msg="obtained new client token: AABRxqilCu+rpyywoA6HxGWb5n9hBZS0JqNr1XjO7QjEdeif+XyTbbLRSQ3EFyW9WE7t0cBj2bltl6KD1bNzMW41EuDQ6qcZO+y5b5SR1iUUDTQNll4AROAZetf2/biMaggFVBdHqI5JaRp8sD3sqPrebdFhlAb7aetVu8tJ78y+9FTQWYRakRI0haY8EOF9AC7GpKjSpg8g7/gePWmtMZ+78FN7eLgQ6UsTAqsP79M4a+3hkHHyDq9oHQ==" Feb 13 09:08:59 volumio go-librespot[25301]: time="2026-02-13T09:08:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" 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"