Feb 11 07:01:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 11 07:01:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:02 volumio go-librespot[7827]: go-librespot daemon starting... Feb 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+07:00" level=debug msg="app state loaded" Feb 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:02 volumio volumio[7739]: info: Loading plugin "ytmusic"... Feb 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+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 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+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 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+07:00" level=info msg="zeroconf server listening on port 34477" Feb 11 07:01:02 volumio go-librespot[7828]: time="2026-02-11T07:01:02+07:00" level=debug msg="obtained new client token: AAAKZmyuQnUPnMt24iuYTQ2ROWJs44xPo1ma+D1AmfhtZkydpvwP0N3AeYdAuVzjs5CT96VHjAP113na0yesIwnrFl75Mg5HjpeEsJjwgX/f03sSrhQubhhactLKUKhAn9xrOCS9Gl6CCeg0cpSR1odEBK3DrK7D8QK4tQ4DGzr9UNtkmi+pn9Ag3gT5lkXmAs/ItCskWgmQ/GaXNsBHu1auccC41BpvrVtW0wmLCa8OGKl24Bxz7QxyHw==" Feb 11 07:01:03 volumio go-librespot[7828]: time="2026-02-11T07:01:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:03 volumio go-librespot[7828]: time="2026-02-11T07:01:03+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:03 volumio go-librespot[7828]: time="2026-02-11T07:01:03+07:00" level=debug msg="completed challenge" Feb 11 07:01:03 volumio go-librespot[7828]: time="2026-02-11T07:01:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:03 volumio volumio-remote-updater[643]: [2026-02-11 07:01:03] [connect] Successful connection Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "outputs"... Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "albumart"... Feb 11 07:01:03 volumio volumio[7739]: info: Plugin example_plugin is not enabled Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "inputs"... Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "updater_comm"... Feb 11 07:01:03 volumio volumio[7739]: info: Plugin mpdemulation is not enabled Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "rest_api"... Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "websocket"... Feb 11 07:01:03 volumio volumio[7739]: info: Starting Socket.io Server version 1.7.4 Feb 11 07:01:03 volumio volumio[7739]: info: Loading plugin "RoonBridge"... Feb 11 07:01:04 volumio volumio[7739]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 07:01:04 volumio volumio[7739]: info: Loading i18n strings for locale en Feb 11 07:01:04 volumio volumio[7739]: Updating browse sources language Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::initPlayerControls Feb 11 07:01:04 volumio volumio[7850]: Forking 3 albumart workers Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 07:01:04 volumio volumio[7739]: Express server listening on port 3000 Feb 11 07:01:04 volumio volumio[7739]: [Metrics] WebUI: 16s 106.07ms Feb 11 07:01:04 volumio volumio[7739]: info: CoreStateMachine::resetVolumioState Feb 11 07:01:04 volumio volumio[7739]: info: CoreStateMachine::getcurrentVolume Feb 11 07:01:04 volumio volumio[7739]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 07:01:04 volumio sudo[7892]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 07:01:04 volumio sudo[7892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:04 volumio sudo[7892]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:04 volumio sudo[7894]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 07:01:04 volumio sudo[7894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:05 volumio sudo[7894]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:05 volumio volumio[7739]: info: Volumio Network Manager: Network status updated: 1 Feb 11 07:01:05 volumio volumio[7739]: info: VolumeController:: Volume=100 Mute =false Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::pushState Feb 11 07:01:05 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::updateTrackBlock Feb 11 07:01:05 volumio volumio[7739]: info: CorePlayQueue::getTrackBlock Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 07:01:05 volumio volumio-remote-updater[643]: [2026-02-11 07:01:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770768063 101 Feb 11 07:01:05 volumio volumio[7739]: 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 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:05 volumio volumio[7739]: info: Reloading queue from file Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::setRepeat null single undefined Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::pushState Feb 11 07:01:05 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::setRandom null Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::pushState Feb 11 07:01:05 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:05 volumio volumio[7739]: info: Setting Device type: Raspberry PI Feb 11 07:01:05 volumio volumio[7739]: info: Completed loading Core Plugins Feb 11 07:01:05 volumio volumio[7739]: info: Preparing to generate the ALSA configuration file Feb 11 07:01:05 volumio volumio[7739]: info: VolumeController:: Volume=100 Mute =false Feb 11 07:01:05 volumio volumio[7739]: info: CoreStateMachine::pushState Feb 11 07:01:05 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:05 volumio volumio[7739]: info: Asound.conf file unchanged, so no further update is needed Feb 11 07:01:05 volumio volumio[7739]: info: Output device has changed, restarting MPD Feb 11 07:01:05 volumio volumio[7739]: info: Output device has changed, restarting Shairport Sync Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:05 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:05 volumio sudo[7912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 07:01:05 volumio sudo[7912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:05 volumio sudo[7914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 07:01:05 volumio volumio[7739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 07:01:05 volumio volumio[7739]: info: ___________ START PLUGINS ___________ Feb 11 07:01:05 volumio sudo[7914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:05 volumio volumio[7739]: info: ControllerMpd::onStart: Initializing MPD Feb 11 07:01:05 volumio volumio[7739]: info: Creating MPD Configuration file Feb 11 07:01:05 volumio sudo[7914]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:05 volumio sudo[7917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 07:01:05 volumio sudo[7917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:06 volumio volumio[7739]: info: [1770768066025] CoreMusicLibrary::Adding element Media Servers Feb 11 07:01:06 volumio sudo[7924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 07:01:06 volumio sudo[7912]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:06 volumio sudo[7924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:06 volumio sudo[7924]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:06 volumio sudo[7927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 07:01:06 volumio sudo[7927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:06 volumio volumio[7739]: info: UPNP Browser: Client initialized successfully Feb 11 07:01:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:06 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 07:01:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 07:01:06 volumio systemd[1]: mpd.service: Consumed 7.027s CPU time. Feb 11 07:01:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 07:01:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 07:01:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 07:01:06 volumio volumio[7739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 07:01:06 volumio volumio[7739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:06 volumio volumio[7739]: info: [1770768066410] CoreMusicLibrary::Adding element Last_100 Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:06 volumio volumio[7739]: info: [1770768066431] CoreMusicLibrary::Adding element Webradio Feb 11 07:01:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:06 volumio go-librespot[7940]: go-librespot daemon starting... Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 07:01:06 volumio volumio[7739]: info: Initializing BBC Radios Feb 11 07:01:06 volumio go-librespot[7941]: time="2026-02-11T07:01:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:06 volumio go-librespot[7941]: time="2026-02-11T07:01:06+07:00" level=debug msg="app state loaded" Feb 11 07:01:06 volumio go-librespot[7941]: time="2026-02-11T07:01:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:06 volumio volumio[7739]: info: Creating Spotify config file Feb 11 07:01:06 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:06 volumio sudo[7939]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 07:01:06 volumio sudo[7939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 07:01:06 volumio sudo[7939]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=info msg="zeroconf server listening on port 37543" Feb 11 07:01:07 volumio volumio[7862]: Starting albumart workers Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="obtained new client token: AACRrlsbWbZOz+hTztfTqcuYxSs8M8ws9MdPCtCd7p81VDZ3oCabnA3uV4dEVkQyGEE+yshSeK3YMXr0S04hiSkYW82ngckstwg4a8Mkfnv/rZuMNl2G5JZjGQyUarqNTtE4+uLQb2ErO5jyknXKKKLdHUrzAm3d8IntERv8p8V4hSl5nEMU6BQOo7oWCHHZNEAuJaQTaR2aNLLSHOkvcShCzHkBCwOyD5k+k+LE4Yg+MKo+a018KdXQcg==" Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:07 volumio go-librespot[7941]: time="2026-02-11T07:01:07+07:00" level=debug msg="completed challenge" Feb 11 07:01:08 volumio go-librespot[7941]: time="2026-02-11T07:01: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 11 07:01:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:08 volumio volumio[7860]: Starting albumart workers Feb 11 07:01:08 volumio volumio[7739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:08 volumio volumio[7739]: info: [1770768068487] CoreMusicLibrary::Adding element YouTube Music Feb 11 07:01:08 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:08 volumio volumio[7739]: Cannot find translation for source YouTube Music Feb 11 07:01:08 volumio volumio[7739]: info: Volumio Calling Home Feb 11 07:01:08 volumio volumio[7861]: Starting albumart workers Feb 11 07:01:08 volumio sudo[7964]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 07:01:08 volumio sudo[7964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:08 volumio sudo[7964]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:09 volumio volumio[7739]: info: MPD Permissions set Feb 11 07:01:09 volumio volumio[7739]: info: MPD Permissions set Feb 11 07:01:09 volumio volumio[7739]: info: Upmpdcli Daemon Started Feb 11 07:01:09 volumio volumio[7739]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 07:01:09 volumio volumio[7739]: info: Discovery: Found device Volumio Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:09 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:09 volumio volumio[7739]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 07:01:09 volumio volumio[7739]: info: Discovery: Found device Volumio Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:09 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:09 volumio volumio[7739]: info: Volumio called home Feb 11 07:01:09 volumio volumio[7739]: info: Spotify config file written Feb 11 07:01:09 volumio sudo[7970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 07:01:09 volumio sudo[7970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:09 volumio volumio[7739]: 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 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:09 volumio volumio[7739]: info: No need to fix Spotify hosts Feb 11 07:01:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:09 volumio go-librespot[7982]: go-librespot daemon starting... Feb 11 07:01:09 volumio sudo[7970]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:09 volumio go-librespot[7984]: time="2026-02-11T07:01:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:09 volumio go-librespot[7984]: time="2026-02-11T07:01:09+07:00" level=debug msg="app state loaded" Feb 11 07:01:09 volumio go-librespot[7984]: time="2026-02-11T07:01:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:10 volumio go-librespot[7984]: time="2026-02-11T07:01:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:10 volumio go-librespot[7984]: time="2026-02-11T07:01:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 07:01:10 volumio go-librespot[7984]: time="2026-02-11T07:01:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 07:01:10 volumio go-librespot[7984]: time="2026-02-11T07:01:10+07:00" level=info msg="zeroconf server listening on port 41651" Feb 11 07:01:10 volumio go-librespot[7984]: time="2026-02-11T07:01:10+07:00" level=debug msg="obtained new client token: AAB2/y9WPg3Hi9oXlXtjl+PbAMuFpECVaFhnbWfEz8mlkTG2Knuuc6V5N1MRAyQXWaPsrwA5FBf3i9z1zs2i6307TQsDJegVzKDPvS3lUoMCXrIPr4i2aL50TYh11Bj8I2kEjhVHpGaAI80CsfE37F89W9UfK4Q/nFowBJx05hM0e3WyRPYbi7Dtb14+OhDPAdhomDCNc52joqmQr7IoliPVR1xcIKj+D3EPyxPSZovjEOeg2OaWPcaspw==" Feb 11 07:01:10 volumio go-librespot[7984]: time="2026-02-11T07:01:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:11 volumio volumio[7739]: info: Starting Shairport Sync Feb 11 07:01:11 volumio go-librespot[7984]: time="2026-02-11T07:01:11+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:11 volumio go-librespot[7984]: time="2026-02-11T07:01:11+07:00" level=debug msg="completed challenge" Feb 11 07:01:11 volumio volumio[7739]: info: Starting Shairport Sync Feb 11 07:01:11 volumio volumio[7739]: info: Starting Shairport Sync Feb 11 07:01:11 volumio sudo[8010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 07:01:11 volumio sudo[8010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:11 volumio go-librespot[7984]: time="2026-02-11T07:01:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:11 volumio sudo[8013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 07:01:11 volumio sudo[8013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:11 volumio sudo[8015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 07:01:11 volumio sudo[8015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:11 volumio volumio[7739]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 07:01:11 volumio volumio[7739]: SPOTIFY: BQCTFhq62kpStEiICIDSaENUY23aiEj6j-0lX6gmm-3-jRpI43hR-yqDyMOQiLf-XENpZCo4gCExVVRRwWGa8oFxg-pM-qNkucO3JXMTlgf4GKPFRDlo4RChiVujwHCeOD3SXUt2sSY6CVJegVg_tVpi5KNPnPEv9JqECc3Tlbxn-5anjpyfy271kWqUNOTEEa25JAwtaEn0uRSZEzVhbfcKwOCXmlKoKbmIUUMGuIdZfH-FfLwJTUFrVPjNDTJ-iUfShP4W-sbNYN53I6LkIRA3px1HRYHFw9NrYcZM9Np-OVjcbOCdRtcJ Feb 11 07:01:11 volumio volumio[7739]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 07:01:11 volumio volumio[7739]: info: New Spotify access token = BQCTFhq62kpStEiICIDSaENUY23aiEj6j-0lX6gmm-3-jRpI43hR-yqDyMOQiLf-XENpZCo4gCExVVRRwWGa8oFxg-pM-qNkucO3JXMTlgf4GKPFRDlo4RChiVujwHCeOD3SXUt2sSY6CVJegVg_tVpi5KNPnPEv9JqECc3Tlbxn-5anjpyfy271kWqUNOTEEa25JAwtaEn0uRSZEzVhbfcKwOCXmlKoKbmIUUMGuIdZfH-FfLwJTUFrVPjNDTJ-iUfShP4W-sbNYN53I6LkIRA3px1HRYHFw9NrYcZM9Np-OVjcbOCdRtcJ Feb 11 07:01:11 volumio volumio[7739]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 07:01:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 07:01:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 07:01:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:11 volumio systemd[1]: shairport-sync.service: Consumed 2.416s CPU time. Feb 11 07:01:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:11 volumio sudo[8010]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:11 volumio sudo[8013]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 07:01:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 07:01:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:11 volumio volumio[7739]: info: Shairport-Sync Started Feb 11 07:01:11 volumio volumio[7739]: Error adding Membership: Error: addMembership EINVAL Feb 11 07:01:11 volumio volumio[7739]: info: Shairport-Sync Started Feb 11 07:01:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:11 volumio sudo[8015]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:11 volumio volumio[7739]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:11 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:11 volumio volumio[7739]: info: Shairport-Sync Started Feb 11 07:01:11 volumio volumio[7739]: 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 11 07:01:11 volumio volumio[7739]: info: Spotify Successfully logged in Feb 11 07:01:11 volumio volumio[7739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:11 volumio volumio[7739]: info: [1770768071979] CoreMusicLibrary::Adding element Spotify Feb 11 07:01:11 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:11 volumio volumio[7739]: Cannot find translation for source YouTube Music Feb 11 07:01:11 volumio volumio[7739]: Cannot find translation for source Spotify Feb 11 07:01:12 volumio volumio[7739]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 07:01:12 volumio volumio[7739]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 07:01:13 volumio volumio[7739]: info: VolumeController:: Volume=100 Mute =false Feb 11 07:01:13 volumio volumio[7739]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:13 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:13 volumio volumio[7739]: info: CoreStateMachine::pushState Feb 11 07:01:13 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:13 volumio volumio[7739]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:14 volumio volumio[7739]: info: go-librespot daemon successfully initialized Feb 11 07:01:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 11 07:01:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:14 volumio mpd[7962]: 2026-02-11T07:01:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 07:01:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:14 volumio go-librespot[8053]: go-librespot daemon starting... Feb 11 07:01:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 07:01:14 volumio sudo[7917]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:14 volumio sudo[7927]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=debug msg="app state loaded" Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:14 volumio volumio[7739]: error: MPD error: The expression evaluated to a falsy value: Feb 11 07:01:14 volumio volumio[7739]: assert.ok(self.idling) Feb 11 07:01:14 volumio volumio[7739]: error: The expression evaluated to a falsy value: Feb 11 07:01:14 volumio volumio[7739]: assert.ok(self.idling) Feb 11 07:01:14 volumio volumio[7739]: info: Completed starting Core Plugins Feb 11 07:01:14 volumio volumio[7739]: info: ------------------------------------------- Feb 11 07:01:14 volumio volumio[7739]: info: ----- MyVolumio plugins startup ---- Feb 11 07:01:14 volumio volumio[7739]: info: ------------------------------------------- Feb 11 07:01:14 volumio volumio[7739]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 07:01:14 volumio volumio[7739]: info: MPD running with PID7962 Feb 11 07:01:14 volumio volumio[7739]: ,establishing connection Feb 11 07:01:14 volumio volumio[7739]: error: updateQueue error: null Feb 11 07:01:14 volumio volumio[7739]: error: updateQueue error: null Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 07:01:14 volumio go-librespot[8056]: time="2026-02-11T07:01:14+07:00" level=info msg="zeroconf server listening on port 40937" Feb 11 07:01:15 volumio go-librespot[8056]: time="2026-02-11T07:01:15+07:00" level=debug msg="obtained new client token: AACXji7rAUDOLRuhkkVOjXIYmwpjZFNAH8pNxNA1rA0+GMTIC7G109n0JwO+yDgtTUpgS6CKk10cNdofD4hXJ2tEH9Ea8wcsfPAuOVD2j32crh6a7kWKjphMalcE1B9GcweoeF3g/1RlEb8ODosqUybKTDswJcCK7Nzx3Fo7borUhXp4bKur9VDUmSfT452FUC5rCGP6ypRCFxoL79KqcTDMhpdiCESzaMjFhr1MPLWIPye8VOd7rHg=" Feb 11 07:01:15 volumio go-librespot[8056]: time="2026-02-11T07:01:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:15 volumio go-librespot[8056]: time="2026-02-11T07:01:15+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:15 volumio go-librespot[8056]: time="2026-02-11T07:01:15+07:00" level=debug msg="completed challenge" Feb 11 07:01:15 volumio go-librespot[8056]: time="2026-02-11T07:01:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:17 volumio volumio[7739]: info: Initializing connection to go-librespot Websocket Feb 11 07:01:17 volumio volumio[7739]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 07:01:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 11 07:01:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:18 volumio go-librespot[8065]: go-librespot daemon starting... Feb 11 07:01:18 volumio go-librespot[8066]: time="2026-02-11T07:01:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:18 volumio go-librespot[8066]: time="2026-02-11T07:01:18+07:00" level=debug msg="app state loaded" Feb 11 07:01:18 volumio go-librespot[8066]: time="2026-02-11T07:01:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+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 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+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 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=info msg="zeroconf server listening on port 44377" Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=debug msg="obtained new client token: AABO5ELkhXBF01gx485ly3zDt7UotTwlkOfVOgmAIxzSF91czYemeyCBg5gxJbY6pxD9OI+iOAfMgYWJap0UwUBiPQhfoNLpHtwR5OvVmuRz1mxJywFdTICWrztM808oDnKrMwuqKZ3dEFJYUwcKeH2OyqYzE69Tu/fFgPc8y6XDybT4g27B0yrXRHfQrethkiu7ebplQhKY063b/Ih06FOtikowImIJr06Cxqg+YryjmXKhXPnF/i1cJA==" Feb 11 07:01:19 volumio volumio[7739]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=debug msg="completed challenge" Feb 11 07:01:19 volumio go-librespot[8066]: time="2026-02-11T07:01:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:20 volumio volumio[7739]: info: Initializing connection to go-librespot Websocket Feb 11 07:01:20 volumio volumio[7739]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 07:01:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 11 07:01:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:22 volumio go-librespot[8073]: go-librespot daemon starting... Feb 11 07:01:22 volumio go-librespot[8074]: time="2026-02-11T07:01:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:22 volumio go-librespot[8074]: time="2026-02-11T07:01:22+07:00" level=debug msg="app state loaded" Feb 11 07:01:22 volumio go-librespot[8074]: time="2026-02-11T07:01:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:23 volumio volumio[7739]: info: Initializing connection to go-librespot Websocket Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=debug msg="new websocket client" Feb 11 07:01:23 volumio volumio[7739]: info: Connection to go-librespot Websocket established Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+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 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+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 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=info msg="zeroconf server listening on port 43103" Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 07:01:23 volumio volumio[7739]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=debug msg="obtained new client token: AACDJ/KcXSuOCyikK9LUWjfkt+f0vzBFjKUGyx8wdHEXIBZplsRlA8wi1pQeL+rvzq4r0op7Ex90sf9lfHnG/frj8SttXX3Xlv9XI8YGKuMN+UZVgWZVKKbpRvG3oHsrdPjZLD2ckg+3gtsAjVY4ZLiYNLVf07ml2b9DbHWZQW78pAWSMIE3GB6VAPLulvCVtwnn39p2EI1TGpuXW59NN6dCPIOAvvb0ouQvw9DCJAMhesMnuuouYg3v2Q==" Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+07:00" level=debug msg="completed challenge" Feb 11 07:01:23 volumio go-librespot[8074]: time="2026-02-11T07:01:23+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 11 07:01:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:25 volumio volumio[7739]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 07:01:25 volumio volumio[7739]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 07:01:25 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:25 volumio volumio[7739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:25 volumio volumio[7739]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 07:01:25 volumio volumio[7739]: info: MyVolumio login type: Token Feb 11 07:01:25 volumio volumio[7739]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 07:01:25 volumio volumio[7739]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 07:01:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 11 07:01:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:27 volumio go-librespot[8097]: go-librespot daemon starting... Feb 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+07:00" level=debug msg="app state loaded" Feb 11 07:01:27 volumio volumio[7739]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 07:01:27 volumio volumio[7739]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 07:01:27 volumio volumio[7739]: info: Streaming services startup Feb 11 07:01:27 volumio volumio[7739]: info: Starting Streaming Daemon Feb 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:27 volumio sudo[8105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 07:01:27 volumio sudo[8105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:27 volumio volumio[7739]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 07:01:27 volumio sudo[8105]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:27 volumio volumio[7739]: info: Getting Spotify volume Feb 11 07:01:27 volumio volumio[7739]: info: Connection to go-librespot Websocket closed Feb 11 07:01:27 volumio volumio[7739]: error: Cannot start Volumio Streaming Daemon Feb 11 07:01:27 volumio volumio[7739]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 07:01:27 volumio volumio[7739]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 07:01:27 volumio volumio[7739]: 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 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+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 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+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 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+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 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+07:00" level=info msg="zeroconf server listening on port 46663" Feb 11 07:01:27 volumio volumio[7739]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:27 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:27 volumio volumio[7739]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 11 07:01:27 volumio volumio[7739]: SPOTIFY: SPOTIFY VOLUME undefined Feb 11 07:01:27 volumio volumio[7739]: SPOTIFY: VOLUMIO VOLUME 100 Feb 11 07:01:27 volumio volumio[7739]: info: Aligning Spotify Volume to Volumio Volume Feb 11 07:01:27 volumio volumio[7739]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:27 volumio volumio[7739]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:27 volumio volumio[7739]: info: Setting Spotify Volume from Volumio: 100 Feb 11 07:01:27 volumio go-librespot[8098]: time="2026-02-11T07:01:27+07:00" level=debug msg="obtained new client token: AADcAqnjNb7nvhzvVzVWeVGaYPb2kbKTmuLZUSbfhM5mLRW4wKAJMrdgSGI456LWtPGyLG1JgsYqi2Fmaln196f9txMXh3dpGM3MyQkrjdMebNssMFQFGE1bI8/E/ggSpOaPnKW7GV5ghY/Ffg/UWduQ1VvfAF1O8MAc4kinjg/2gOlfo9D8ghJQWhUk26q/deQX9bQd65AMO2qgvXsfbkp7Q9K35WxB1x4MMkhfdA16mNVzSdE66Xe/5g==" Feb 11 07:01:28 volumio go-librespot[8098]: time="2026-02-11T07:01:28+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 11 07:01:28 volumio go-librespot[8098]: time="2026-02-11T07:01:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 07:01:28 volumio go-librespot[8098]: time="2026-02-11T07:01:28+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:28 volumio go-librespot[8098]: time="2026-02-11T07:01:28+07:00" level=debug msg="completed challenge" Feb 11 07:01:28 volumio go-librespot[8098]: time="2026-02-11T07:01:28+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 11 07:01:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:28 volumio volumio[7739]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 07:01:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:28 volumio volumio[7739]: Error: socket hang up Feb 11 07:01:28 volumio volumio[7739]: at connResetException (node:internal/errors:720:14) Feb 11 07:01:28 volumio volumio[7739]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 07:01:28 volumio volumio[7739]: at Socket.emit (node:events:526:35) Feb 11 07:01:28 volumio volumio[7739]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 07:01:28 volumio volumio[7739]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 07:01:28 volumio volumio[7739]: code: 'ECONNRESET', Feb 11 07:01:28 volumio volumio[7739]: response: undefined Feb 11 07:01:28 volumio volumio[7739]: } Feb 11 07:01:28 volumio volumio[7739]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 07:01:29 volumio sudo[8126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 07:00' Feb 11 07:01:29 volumio sudo[8126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:30 volumio sudo[8126]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 11 07:01:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:31 volumio go-librespot[8134]: go-librespot daemon starting... Feb 11 07:01:31 volumio go-librespot[8135]: time="2026-02-11T07:01:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:31 volumio go-librespot[8135]: time="2026-02-11T07:01:31+07:00" level=debug msg="app state loaded" Feb 11 07:01:31 volumio go-librespot[8135]: time="2026-02-11T07:01:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:31 volumio volumio-remote-updater[643]: [2026-02-11 07:01:31] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 11 07:01:31 volumio volumio-remote-updater[643]: [2026-02-11 07:01:31] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 11 07:01:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 07:01:31 volumio systemd[1]: volumio.service: Consumed 55.864s CPU time. Feb 11 07:01:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 07:01:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 07:01:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11401. Feb 11 07:01:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 07:01:31 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 07:01:31 volumio systemd[1]: volumio.service: Consumed 55.864s CPU time. Feb 11 07:01:31 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 07:01:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+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 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+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 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+07:00" level=info msg="zeroconf server listening on port 36915" Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+07:00" level=debug msg="obtained new client token: AABEHAOfZUplFqjLQRBts+bnOGZxfmB6YPDQ8DqFJoZcr5eSz1heLXrFjAJUgoI9892uytSSRko2jvI05LrmQF/gUpCM0RNulhytXAv293Su0MCIT9QWz5kO7RLUY7WOez1PFJRacoBvh1PNLtyRUrbCiPfDPQSqe/tC+Ahfh/iv1JRxQ4JCyKw4EQ+5rKe3A9fnWrmBwlVGOIxea9a78iRXgEYhp+OjyL54JI1X8t1ak4FHjHdD+d4=" Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+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 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+07:00" level=debug msg="completed challenge" Feb 11 07:01:32 volumio go-librespot[8135]: time="2026-02-11T07:01:32+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 11 07:01:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:35 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:01:35 volumio volumio[8155]: info: ----- Volumio3 ---- Feb 11 07:01:35 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:01:35 volumio volumio[8155]: info: ----- System startup ---- Feb 11 07:01:35 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:01:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 11 07:01:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:35 volumio go-librespot[8180]: go-librespot daemon starting... Feb 11 07:01:35 volumio go-librespot[8181]: time="2026-02-11T07:01:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:35 volumio go-librespot[8181]: time="2026-02-11T07:01:35+07:00" level=debug msg="app state loaded" Feb 11 07:01:35 volumio go-librespot[8181]: time="2026-02-11T07:01:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+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 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+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 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+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 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+07:00" level=info msg="zeroconf server listening on port 38577" Feb 11 07:01:36 volumio nmbd[966]: [2026/02/11 07:01:36.558824, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 11 07:01:36 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 11 07:01:36 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 11 07:01:36 volumio volumio-remote-updater[643]: [2026-02-11 07:01:36] [connect] Successful connection Feb 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+07:00" level=debug msg="obtained new client token: AADiBm/Lc7q9WbA6koOszKBGsPF5mdI+4ji1rfgPV8vfIC+iiO5kMD7GBIJ4u1K+gXX6ntsNxFCK4S7H+jvQxM5R8xnjvgPokZ+WRKhB7giV5KsXECjm+TyQQjfzNqA5/ZJUAYa3AQTIRTEXy8J0wc+lWwdO7m+cYIO97DsGDMlNkurud75G/FoNBymlwBCLIDpgCFgagC5jnsIFmZGxF5jdXBPFECUUWx5dL6BrfygvKD9Rpl6xBdwoLg==" Feb 11 07:01:36 volumio volumio[8155]: info: MYVOLUMIO Environment detected Feb 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+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 11 07:01:36 volumio go-librespot[8181]: time="2026-02-11T07:01:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 07:01:36 volumio volumio[8155]: info: Plugin folders cleanup Feb 11 07:01:36 volumio volumio[8155]: info: Scanning into folder /volumio/app/plugins/ Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category audio_interface Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category miscellanea Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category music_service Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category plugins.json Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category system_controller Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category user_interface Feb 11 07:01:36 volumio volumio[8155]: info: Scanning into folder /data/plugins/ Feb 11 07:01:36 volumio volumio[8155]: info: Scanning category music_service Feb 11 07:01:36 volumio volumio[8155]: info: Plugin folders cleanup completed Feb 11 07:01:36 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:01:36 volumio volumio[8155]: info: ----- Core plugins startup ---- Feb 11 07:01:36 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:01:36 volumio volumio[8155]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 07:01:36 volumio volumio[8155]: info: Adding plugin upnp to MyMusic Plugins Feb 11 07:01:36 volumio volumio[8155]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 07:01:36 volumio volumio[8155]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 07:01:36 volumio volumio[8155]: info: Loading plugins from folder /data/plugins/ Feb 11 07:01:36 volumio volumio[8155]: info: Loading plugin "system"... Feb 11 07:01:37 volumio go-librespot[8181]: time="2026-02-11T07:01:37+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:37 volumio go-librespot[8181]: time="2026-02-11T07:01:37+07:00" level=debug msg="completed challenge" Feb 11 07:01:37 volumio volumio[8155]: info: Loading plugin "appearance"... Feb 11 07:01:37 volumio go-librespot[8181]: time="2026-02-11T07:01:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:38 volumio volumio[8155]: info: Loading plugin "network"... Feb 11 07:01:38 volumio volumio[8155]: info: Refreshing Cached IP Addresses Feb 11 07:01:38 volumio sudo[8196]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 07:01:38 volumio sudo[8196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:39 volumio sudo[8198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 07:01:39 volumio sudo[8198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:39 volumio sudo[8196]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:39 volumio sudo[8198]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "services"... Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "alsa_controller"... Feb 11 07:01:39 volumio sudo[8209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 07:01:39 volumio sudo[8209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:39 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "wizard"... Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "networkfs"... Feb 11 07:01:39 volumio volumio[8155]: info: Starting Udev Watcher for removable devices Feb 11 07:01:39 volumio volumio[8155]: info: Ignoring mount for partition: boot Feb 11 07:01:39 volumio volumio[8155]: info: Ignoring mount for partition: volumio Feb 11 07:01:39 volumio volumio[8155]: info: Ignoring mount for partition: volumio_data Feb 11 07:01:39 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "volumio_command_line_client"... Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "upnp"... Feb 11 07:01:39 volumio volumio[8155]: info: [1770768099323] Starting Upmpd Daemon Feb 11 07:01:39 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "my_music"... Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "mpd"... Feb 11 07:01:39 volumio volumio[8155]: info: Loading plugin "upnp_browser"... Feb 11 07:01:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 11 07:01:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:40 volumio go-librespot[8229]: go-librespot daemon starting... Feb 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+07:00" level=debug msg="app state loaded" Feb 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+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 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+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 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+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 11 07:01:40 volumio go-librespot[8230]: time="2026-02-11T07:01:40+07:00" level=info msg="zeroconf server listening on port 37523" Feb 11 07:01:41 volumio go-librespot[8230]: time="2026-02-11T07:01:41+07:00" level=debug msg="obtained new client token: AAAa8wnp4Sr1VXmazHgZgQvbIOirXgYQVbhVAqm/XUQXrOpWd66aMc2k2kbVzYgL7HSQlzlQN8BTc3OXQet0BexzauvgWpoQYHPZomHnywbp+jjgsFv94DAmHQq7ZFGareQcjjtmNKx38ZcU4uiieq51YSBDiFnRT9TZcxDTsGqDTgkgrUDsnd120ABFh2mnBwAvvCS5pxsURy+g3vN1+4+Xo3FJ5SJoRfl7zabiKgV4B+PO3/PDHxg=" Feb 11 07:01:41 volumio go-librespot[8230]: time="2026-02-11T07:01:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:41 volumio go-librespot[8230]: time="2026-02-11T07:01:41+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:41 volumio go-librespot[8230]: time="2026-02-11T07:01:41+07:00" level=debug msg="completed challenge" Feb 11 07:01:41 volumio go-librespot[8230]: time="2026-02-11T07:01:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:41 volumio sudo[8209]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:42 volumio volumio[8155]: info: Starting UPNP Browser Feb 11 07:01:42 volumio volumio[8155]: info: Loading plugin "alarm-clock"... Feb 11 07:01:43 volumio volumio[8155]: info: Loading plugin "airplay_emulation"... Feb 11 07:01:43 volumio volumio[8155]: info: Starting Shairport Sync Feb 11 07:01:43 volumio volumio[8155]: info: Loading plugin "last_100"... Feb 11 07:01:43 volumio volumio[8155]: info: Loading plugin "webradio"... Feb 11 07:01:43 volumio volumio[8155]: info: Loading plugin "i2s_dacs"... Feb 11 07:01:43 volumio volumio[8155]: info: Loading plugin "volumiodiscovery"... Feb 11 07:01:43 volumio volumio[8155]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 07:01:43 volumio volumio[8155]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 07:01:43 volumio volumio[8155]: *** WARNING *** For more information see Feb 11 07:01:43 volumio volumio[8155]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 07:01:43 volumio volumio[8155]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 07:01:43 volumio volumio[8155]: *** WARNING *** For more information see Feb 11 07:01:43 volumio node[8155]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 07:01:43 volumio node[8155]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 07:01:43 volumio node[8155]: *** WARNING *** For more information see Feb 11 07:01:43 volumio node[8155]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 07:01:43 volumio node[8155]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 07:01:43 volumio node[8155]: *** WARNING *** For more information see Feb 11 07:01:43 volumio volumio[8155]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 07:01:43 volumio volumio[8155]: info: Discovery: Started advertising with name: Volumio Feb 11 07:01:43 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 07:01:43 volumio volumio[8155]: info: Loading plugin "spop"... Feb 11 07:01:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 11 07:01:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:44 volumio go-librespot[8240]: go-librespot daemon starting... Feb 11 07:01:44 volumio go-librespot[8241]: time="2026-02-11T07:01:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:44 volumio go-librespot[8241]: time="2026-02-11T07:01:44+07:00" level=debug msg="app state loaded" Feb 11 07:01:44 volumio go-librespot[8241]: time="2026-02-11T07:01:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=info msg="zeroconf server listening on port 37775" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="obtained new client token: AAB6CF4Qfx68LnxFUe+CDChAvYrz1E5mqA8zg7aP8SXMXRmg7MbPzzt7NBVJytzNceTLfwccltG1ipcuUFc599N0sDeeWL5l5VDM4aHoowDvjXyW1PsNzZZkWIk1vF4Ss8d+1OHQDau3vRAt3WJ+57uCCa4BO5RAhcytSnbmU1wPEzNp0aYaQab97mAvYg65fxyTEDrawwxpPgmCxBc5sPxvbNK6iYs91E8TPPT0TASxYSe28NQfwRHAmA==" Feb 11 07:01:45 volumio volumio[8155]: info: Loading plugin "ytcr"... Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+07:00" level=debug msg="completed challenge" Feb 11 07:01:45 volumio go-librespot[8241]: time="2026-02-11T07:01:45+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 11 07:01:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:48 volumio volumio[8155]: info: Loading plugin "ytmusic"... Feb 11 07:01:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 11 07:01:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:49 volumio volumio-remote-updater[643]: [2026-02-11 07:01:49] [connect] Successful connection Feb 11 07:01:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:49 volumio go-librespot[8248]: go-librespot daemon starting... Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "outputs"... Feb 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+07:00" level=debug msg="app state loaded" Feb 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "albumart"... Feb 11 07:01:49 volumio volumio[8155]: info: Plugin example_plugin is not enabled Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "inputs"... Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "updater_comm"... Feb 11 07:01:49 volumio volumio[8155]: info: Plugin mpdemulation is not enabled Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "rest_api"... Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "websocket"... Feb 11 07:01:49 volumio volumio[8155]: info: Starting Socket.io Server version 1.7.4 Feb 11 07:01:49 volumio volumio[8155]: info: Loading plugin "RoonBridge"... Feb 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+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 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+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 11 07:01:49 volumio go-librespot[8262]: time="2026-02-11T07:01:49+07:00" level=info msg="zeroconf server listening on port 43997" Feb 11 07:01:50 volumio go-librespot[8262]: time="2026-02-11T07:01:50+07:00" level=debug msg="obtained new client token: AAAso1EaTvtU2O4D0mo/L/CqXyCpADJJV0UnuB7IjoFEYDX7vZY2GVNbs6Se5vQIsDH/hu3qXU2D2CQwIZvnUsFtJNClzy2gRNNGyR9AqkbiPHa1/sR6RFGMCXoO0sAPblaKggwGcjJwz0kJ8rQfzo7O1VckCwtPCA03xYnyT7ALTDi7WM/dtVszdOGRbYOy8QT4qmZ0Z4bPZipx08llydyPh659RWJMOfueJGBTwuHuWDy2R5WYm6Y=" Feb 11 07:01:50 volumio volumio[8155]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 07:01:50 volumio go-librespot[8262]: time="2026-02-11T07:01:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:50 volumio volumio[8155]: info: Loading i18n strings for locale en Feb 11 07:01:50 volumio volumio[8155]: Updating browse sources language Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:50 volumio go-librespot[8262]: time="2026-02-11T07:01:50+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:50 volumio go-librespot[8262]: time="2026-02-11T07:01:50+07:00" level=debug msg="completed challenge" Feb 11 07:01:50 volumio go-librespot[8262]: time="2026-02-11T07:01:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:50 volumio volumio[8269]: Forking 3 albumart workers Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::initPlayerControls Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 07:01:50 volumio volumio[8155]: Express server listening on port 3000 Feb 11 07:01:50 volumio volumio[8155]: [Metrics] WebUI: 16s 150.33ms Feb 11 07:01:50 volumio volumio[8155]: info: CoreStateMachine::resetVolumioState Feb 11 07:01:50 volumio volumio[8155]: info: CoreStateMachine::getcurrentVolume Feb 11 07:01:50 volumio volumio[8155]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 07:01:50 volumio sudo[8313]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 07:01:50 volumio sudo[8313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:50 volumio sudo[8316]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 07:01:50 volumio sudo[8316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:50 volumio sudo[8313]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:50 volumio sudo[8316]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:50 volumio volumio[8155]: info: Volumio Network Manager: Network status updated: 1 Feb 11 07:01:51 volumio volumio-remote-updater[643]: [2026-02-11 07:01:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770768109 101 Feb 11 07:01:51 volumio volumio[8155]: 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 11 07:01:51 volumio volumio[8155]: info: VolumeController:: Volume=100 Mute =false Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::pushState Feb 11 07:01:51 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::updateTrackBlock Feb 11 07:01:51 volumio volumio[8155]: info: CorePlayQueue::getTrackBlock Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:51 volumio volumio[8155]: info: Reloading queue from file Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::setRepeat null single undefined Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::pushState Feb 11 07:01:51 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::setRandom null Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::pushState Feb 11 07:01:51 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:51 volumio volumio[8155]: info: Setting Device type: Raspberry PI Feb 11 07:01:51 volumio volumio[8155]: info: Completed loading Core Plugins Feb 11 07:01:51 volumio volumio[8155]: info: Preparing to generate the ALSA configuration file Feb 11 07:01:51 volumio volumio[8155]: info: VolumeController:: Volume=100 Mute =false Feb 11 07:01:51 volumio volumio[8155]: info: CoreStateMachine::pushState Feb 11 07:01:51 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:51 volumio volumio[8155]: info: Asound.conf file unchanged, so no further update is needed Feb 11 07:01:51 volumio volumio[8155]: info: Output device has changed, restarting MPD Feb 11 07:01:51 volumio sudo[8331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 07:01:51 volumio sudo[8331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:51 volumio volumio[8155]: info: Output device has changed, restarting Shairport Sync Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:51 volumio sudo[8333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 07:01:51 volumio sudo[8333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:51 volumio sudo[8333]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:51 volumio volumio[8155]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 07:01:51 volumio volumio[8155]: info: ___________ START PLUGINS ___________ Feb 11 07:01:51 volumio volumio[8155]: info: ControllerMpd::onStart: Initializing MPD Feb 11 07:01:51 volumio volumio[8155]: info: Creating MPD Configuration file Feb 11 07:01:51 volumio sudo[8331]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:51 volumio sudo[8336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 07:01:51 volumio sudo[8336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:51 volumio volumio[8155]: info: [1770768111912] CoreMusicLibrary::Adding element Media Servers Feb 11 07:01:51 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:51 volumio volumio[8155]: info: UPNP Browser: Client initialized successfully Feb 11 07:01:51 volumio sudo[8346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 07:01:51 volumio sudo[8346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:52 volumio sudo[8344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 07:01:52 volumio sudo[8344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:52 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 07:01:52 volumio sudo[8344]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:52 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 07:01:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 07:01:52 volumio systemd[1]: mpd.service: Consumed 7.407s CPU time. Feb 11 07:01:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 07:01:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 07:01:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 07:01:52 volumio volumio[8155]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 07:01:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 07:01:52 volumio volumio[8155]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:52 volumio volumio[8155]: info: [1770768112359] CoreMusicLibrary::Adding element Last_100 Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:52 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 07:01:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 07:01:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 07:01:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 07:01:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:52 volumio volumio[8155]: info: [1770768112396] CoreMusicLibrary::Adding element Webradio Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 07:01:52 volumio volumio[8155]: info: Initializing BBC Radios Feb 11 07:01:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 07:01:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:52 volumio volumio[8155]: info: Creating Spotify config file Feb 11 07:01:52 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:52 volumio sudo[8368]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 07:01:52 volumio sudo[8368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 07:01:52 volumio sudo[8368]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:53 volumio volumio[8280]: Starting albumart workers Feb 11 07:01:53 volumio volumio[8281]: Starting albumart workers Feb 11 07:01:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 11 07:01:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:53 volumio go-librespot[8376]: go-librespot daemon starting... Feb 11 07:01:53 volumio go-librespot[8377]: time="2026-02-11T07:01:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:53 volumio volumio[8282]: Starting albumart workers Feb 11 07:01:53 volumio volumio[8155]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:53 volumio volumio[8155]: info: [1770768113928] CoreMusicLibrary::Adding element YouTube Music Feb 11 07:01:53 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:53 volumio volumio[8155]: Cannot find translation for source YouTube Music Feb 11 07:01:53 volumio volumio[8155]: info: Volumio Calling Home Feb 11 07:01:54 volumio sudo[8384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 07:01:54 volumio sudo[8384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:54 volumio sudo[8384]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:54 volumio go-librespot[8377]: time="2026-02-11T07:01:54+07:00" level=info msg="zeroconf server listening on port 37589" Feb 11 07:01:55 volumio volumio[8155]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 07:01:55 volumio volumio[8155]: info: Discovery: Found device Volumio Feb 11 07:01:55 volumio volumio[8155]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:55 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:55 volumio volumio[8155]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 07:01:55 volumio volumio[8155]: info: Discovery: Found device Volumio Feb 11 07:01:55 volumio volumio[8155]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:55 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:55 volumio volumio[8155]: info: MPD Permissions set Feb 11 07:01:55 volumio volumio[8155]: info: MPD Permissions set Feb 11 07:01:55 volumio volumio[8155]: info: Upmpdcli Daemon Started Feb 11 07:01:55 volumio volumio[8155]: info: Volumio called home Feb 11 07:01:55 volumio volumio[8155]: info: Spotify config file written Feb 11 07:01:55 volumio sudo[8403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 07:01:55 volumio sudo[8403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:55 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 07:01:55 volumio systemd[1]: go-librespot-daemon.service: Killing process 8379 (go-librespot) with signal SIGKILL. Feb 11 07:01:55 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 07:01:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:01:55 volumio go-librespot[8410]: go-librespot daemon starting... Feb 11 07:01:55 volumio sudo[8403]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:55 volumio go-librespot[8412]: time="2026-02-11T07:01:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:01:55 volumio go-librespot[8412]: time="2026-02-11T07:01:55+07:00" level=debug msg="app state loaded" Feb 11 07:01:55 volumio go-librespot[8412]: time="2026-02-11T07:01:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:01:55 volumio volumio[8155]: 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 11 07:01:55 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:55 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 07:01:56 volumio volumio[8155]: info: No need to fix Spotify hosts Feb 11 07:01:56 volumio go-librespot[8412]: time="2026-02-11T07:01: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 11 07:01:56 volumio go-librespot[8412]: time="2026-02-11T07:01: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 11 07:01:56 volumio go-librespot[8412]: time="2026-02-11T07:01: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 11 07:01:56 volumio go-librespot[8412]: time="2026-02-11T07:01:56+07:00" level=info msg="zeroconf server listening on port 35553" Feb 11 07:01:56 volumio volumio[8155]: info: Starting Shairport Sync Feb 11 07:01:56 volumio volumio[8155]: info: Starting Shairport Sync Feb 11 07:01:56 volumio volumio[8155]: info: Starting Shairport Sync Feb 11 07:01:56 volumio sudo[8431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 07:01:56 volumio sudo[8431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:56 volumio volumio[8155]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 07:01:56 volumio volumio[8155]: SPOTIFY: BQA1N0kSM8e2qF_3y6A3MlEwH2DDVQW03M_zsE9i3S5IPIas96wXyj4huLVNMhUoFfwLu6GI1TgR-ADAjSE8XDGd7YsoeIYoZLxsQ8OxYSiSR0EZN8F41fAuewma2EYysplIxaMXZbBivjeMO9KYscd4JmuZvBWD-tA7cevbkn_NF-mULXKwd7bXYPaerS9S05aG2HZhUuHubB7v9xdT4O_QcS1QhLTL8t-ahwyM5Oy0gqdPA3iYAWfGvRe3dX3U_C3WwmO2J9JRrwNarf7dsLW3Y_Q3WFdBAEAQtQxee50SZq6yH0AiW7Dg Feb 11 07:01:56 volumio volumio[8155]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 07:01:56 volumio volumio[8155]: info: New Spotify access token = BQA1N0kSM8e2qF_3y6A3MlEwH2DDVQW03M_zsE9i3S5IPIas96wXyj4huLVNMhUoFfwLu6GI1TgR-ADAjSE8XDGd7YsoeIYoZLxsQ8OxYSiSR0EZN8F41fAuewma2EYysplIxaMXZbBivjeMO9KYscd4JmuZvBWD-tA7cevbkn_NF-mULXKwd7bXYPaerS9S05aG2HZhUuHubB7v9xdT4O_QcS1QhLTL8t-ahwyM5Oy0gqdPA3iYAWfGvRe3dX3U_C3WwmO2J9JRrwNarf7dsLW3Y_Q3WFdBAEAQtQxee50SZq6yH0AiW7Dg Feb 11 07:01:56 volumio volumio[8155]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 07:01:56 volumio go-librespot[8412]: time="2026-02-11T07:01:56+07:00" level=debug msg="obtained new client token: AABiF1z8Iq4oTU4g208H6PGa2pe0UYBNwEXqmrv1SVFamsmXW77BgojDt3FyN0f6HvbeoaH0k154g9MdeQDod5qd/OcwzugoVrz1ZVvJGvcIwm9xYI4OyXfpB9AEczUiOAT4z+g4dRoV2HEqN4YDjcg2zXt3rhn7G/Z5D67z28p/5VRr+ZmE05erL7HoZ0SSdh8lH+3aqpu3PGV7C9YyLI5Cce3T0QRJVCEZ/5hJRiCGnh0x/30SurY4tg==" Feb 11 07:01:56 volumio sudo[8433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 07:01:56 volumio sudo[8433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:56 volumio sudo[8435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 07:01:56 volumio sudo[8435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 07:01:56 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 07:01:56 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 07:01:56 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:56 volumio systemd[1]: shairport-sync.service: Consumed 2.343s CPU time. Feb 11 07:01:57 volumio go-librespot[8412]: time="2026-02-11T07:01:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:01:57 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:57 volumio sudo[8431]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:57 volumio volumio[8155]: info: Shairport-Sync Started Feb 11 07:01:57 volumio volumio[8155]: Error adding Membership: Error: addMembership EINVAL Feb 11 07:01:57 volumio volumio[8155]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:57 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:57 volumio go-librespot[8412]: time="2026-02-11T07:01:57+07:00" level=debug msg="completed keyexchange" Feb 11 07:01:57 volumio go-librespot[8412]: time="2026-02-11T07:01:57+07:00" level=debug msg="completed challenge" Feb 11 07:01:57 volumio go-librespot[8412]: time="2026-02-11T07:01:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:01:57 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 07:01:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:01:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:01:57 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 07:01:57 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:57 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 07:01:57 volumio sudo[8433]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:57 volumio volumio[8155]: 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 11 07:01:57 volumio volumio[8155]: info: Spotify Successfully logged in Feb 11 07:01:57 volumio sudo[8435]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:57 volumio volumio[8155]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 07:01:57 volumio volumio[8155]: info: [1770768117515] CoreMusicLibrary::Adding element Spotify Feb 11 07:01:57 volumio volumio[8155]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 07:01:57 volumio volumio[8155]: Cannot find translation for source YouTube Music Feb 11 07:01:57 volumio volumio[8155]: Cannot find translation for source Spotify Feb 11 07:01:57 volumio volumio[8155]: info: Shairport-Sync Started Feb 11 07:01:57 volumio volumio[8155]: info: Shairport-Sync Started Feb 11 07:01:58 volumio volumio[8155]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 07:01:58 volumio volumio[8155]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 07:01:58 volumio volumio[8155]: info: VolumeController:: Volume=100 Mute =false Feb 11 07:01:58 volumio volumio[8155]: info: CoreCommandRouter::volumioGetState Feb 11 07:01:58 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:58 volumio volumio[8155]: info: CoreStateMachine::pushState Feb 11 07:01:58 volumio volumio[8155]: info: CorePlayQueue::getTrack 0 Feb 11 07:01:58 volumio volumio[8155]: info: CoreCommandRouter::volumioPushState Feb 11 07:01:59 volumio volumio[8155]: info: go-librespot daemon successfully initialized Feb 11 07:01:59 volumio mpd[8375]: 2026-02-11T07:01:59 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 07:01:59 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 07:01:59 volumio sudo[8336]: pam_unix(sudo:session): session closed for user root Feb 11 07:01:59 volumio sudo[8346]: pam_unix(sudo:session): session closed for user root Feb 11 07:02:00 volumio volumio[8155]: error: MPD error: The expression evaluated to a falsy value: Feb 11 07:02:00 volumio volumio[8155]: assert.ok(self.idling) Feb 11 07:02:00 volumio volumio[8155]: error: The expression evaluated to a falsy value: Feb 11 07:02:00 volumio volumio[8155]: assert.ok(self.idling) Feb 11 07:02:00 volumio volumio[8155]: error: updateQueue error: null Feb 11 07:02:00 volumio volumio[8155]: info: MPD running with PID8375 Feb 11 07:02:00 volumio volumio[8155]: ,establishing connection Feb 11 07:02:00 volumio volumio[8155]: info: Completed starting Core Plugins Feb 11 07:02:00 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:02:00 volumio volumio[8155]: info: ----- MyVolumio plugins startup ---- Feb 11 07:02:00 volumio volumio[8155]: info: ------------------------------------------- Feb 11 07:02:00 volumio volumio[8155]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 07:02:00 volumio volumio[8155]: error: updateQueue error: null Feb 11 07:02:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 07:02:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:02:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:02:00 volumio go-librespot[8490]: go-librespot daemon starting... Feb 11 07:02:00 volumio go-librespot[8491]: time="2026-02-11T07:02:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:02:00 volumio go-librespot[8491]: time="2026-02-11T07:02:00+07:00" level=debug msg="app state loaded" Feb 11 07:02:00 volumio go-librespot[8491]: time="2026-02-11T07:02:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02: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 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02: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 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02: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 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02:01+07:00" level=info msg="zeroconf server listening on port 39049" Feb 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02:01+07:00" level=debug msg="obtained new client token: AABmhqNofDe8J4krXyRpi1hxaI3H+XUhbTeBeXVDHxQi+qXrunzC1m3U/21ie4QkoAZ7Eb+FqzZH1dX1Up4sk0sIJZHDpXCN8FQrBFyuo/+72I1MMu0Xn1unG7lSW2rXrHvY4C8E4fLUYNipUrLohyoysjO/OIZZwAh1fqEbvTa1Y9W2yaytJfAL8eGU5HsZYxzrUVMLYnuNIeLJZoli+6LDqFeWiOzFp3GenBNY9Wn97go7TZAzDh/nIA==" Feb 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02:01+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 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02:01+07:00" level=debug msg="completed keyexchange" Feb 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02:01+07:00" level=debug msg="completed challenge" Feb 11 07:02:01 volumio go-librespot[8491]: time="2026-02-11T07:02: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 11 07:02:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:02:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:02:02 volumio volumio[8155]: info: Initializing connection to go-librespot Websocket Feb 11 07:02:02 volumio volumio[8155]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 07:02:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 07:02:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:02:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:02:04 volumio go-librespot[8498]: go-librespot daemon starting... Feb 11 07:02:04 volumio go-librespot[8499]: time="2026-02-11T07:02:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:02:04 volumio go-librespot[8499]: time="2026-02-11T07:02:04+07:00" level=debug msg="app state loaded" Feb 11 07:02:04 volumio go-librespot[8499]: time="2026-02-11T07:02:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:02:05 volumio volumio[8155]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+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 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+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 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=info msg="zeroconf server listening on port 38827" Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=debug msg="obtained new client token: AADCMVNWNH0liUdI2Tp8MzbYs+4XaqLfOnyOuQFG0wWv7RTGvqIz3VJOIyrAGOMCXFImzbUtvC4XU98f923Nn7hECVU1zVYA+NwXd4zy4Gjug3dSCtRVgeUj5i9jfpk9zz4EU9eLndpNt6LZbkGPf1EM+MO4JPvCdOtDPs15HneFdyX0vQ886GIrfStCMuKQ8RTNFXosr7oHMriy1ZXch5BSboU1rp5UeTE1LFqjtc/IOKQJYCeoirp2eQ==" Feb 11 07:02:05 volumio volumio[8155]: info: Initializing connection to go-librespot Websocket Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=debug msg="new websocket client" Feb 11 07:02:05 volumio volumio[8155]: info: Connection to go-librespot Websocket established Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=debug msg="completed keyexchange" Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02:05+07:00" level=debug msg="completed challenge" Feb 11 07:02:05 volumio go-librespot[8499]: time="2026-02-11T07:02: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 11 07:02:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:02:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:02:05 volumio volumio[8155]: info: Connection to go-librespot Websocket closed Feb 11 07:02:08 volumio volumio[8155]: info: Getting Spotify volume Feb 11 07:02:08 volumio volumio[8155]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 07:02:08 volumio volumio[8155]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 07:02:08 volumio volumio[8155]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 07:02:08 volumio volumio[8155]: errno: -111, Feb 11 07:02:08 volumio volumio[8155]: code: 'ECONNREFUSED', Feb 11 07:02:08 volumio volumio[8155]: syscall: 'connect', Feb 11 07:02:08 volumio volumio[8155]: address: '127.0.0.1', Feb 11 07:02:08 volumio volumio[8155]: port: 9879, Feb 11 07:02:08 volumio volumio[8155]: response: undefined Feb 11 07:02:08 volumio volumio[8155]: } Feb 11 07:02:08 volumio volumio[8155]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 07:02:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 07:02:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:02:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 07:02:09 volumio go-librespot[8518]: go-librespot daemon starting... Feb 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+07:00" level=debug msg="app state loaded" Feb 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+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 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+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 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+07:00" level=info msg="zeroconf server listening on port 45109" Feb 11 07:02:09 volumio go-librespot[8519]: time="2026-02-11T07:02:09+07:00" level=debug msg="obtained new client token: AABQvWI8FfLBQiT0KZuydkLSUmsT4JCKuNUwJNJsAOBeyHqVLmU4jS//72MvXvK8qIFOqgk3gsfosduTgwmqZqKhFkElj4shEcJTh6ExpxZnT+TffUiCRU9EX1pDY60AEFbggue3ViFnp08K1mRyD7JDjnLaVvQ7ujubos7zXKvyIt6e6K2l0amSubEBEEbIferptqxiSCSdJaAk5R5RUepsGO3hrlFOzmtL+JPJS/mbH3MEgWz5L/Rmnw==" Feb 11 07:02:10 volumio go-librespot[8519]: time="2026-02-11T07:02:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 07:02:10 volumio go-librespot[8519]: time="2026-02-11T07:02:10+07:00" level=debug msg="completed keyexchange" Feb 11 07:02:10 volumio go-librespot[8519]: time="2026-02-11T07:02:10+07:00" level=debug msg="completed challenge" Feb 11 07:02:10 volumio go-librespot[8519]: time="2026-02-11T07:02:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 07:02:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 07:02:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 07:02:10 volumio sudo[8543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 07:01' Feb 11 07:02:10 volumio sudo[8543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"