Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:00 volumio volumio[20976]: info: Reloading queue from file Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::setRepeat null single undefined Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::pushState Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::setRandom null Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::pushState Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:00 volumio volumio[20976]: info: Setting Device type: Raspberry PI Mar 04 20:58:00 volumio volumio[20976]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::pushState Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::updateTrackBlock Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrackBlock Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:58:00 volumio volumio[20976]: info: Completed loading Core Plugins Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+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]" Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+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]" Mar 04 20:58:00 volumio volumio[20976]: info: Preparing to generate the ALSA configuration file Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+07:00" level=info msg="zeroconf server listening on port 33039" Mar 04 20:58:00 volumio volumio[20976]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:58:00 volumio volumio[20976]: info: Discovery: Found device Volumio Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:00 volumio volumio[20976]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:58:00 volumio volumio[20976]: info: Discovery: Found device Volumio Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:00 volumio volumio[20976]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:58:00 volumio volumio[20976]: info: CoreStateMachine::pushState Mar 04 20:58:00 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:00 volumio volumio[20976]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:58:00 volumio volumio[20976]: info: Output device has changed, restarting MPD Mar 04 20:58:00 volumio volumio[20976]: info: Output device has changed, restarting Shairport Sync Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:00 volumio sudo[21137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:58:00 volumio sudo[21137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:00 volumio sudo[21137]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:00 volumio sudo[21139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:58:00 volumio sudo[21139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:00 volumio volumio[20976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:58:00 volumio volumio[20976]: info: ___________ START PLUGINS ___________ Mar 04 20:58:00 volumio volumio[20976]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:58:00 volumio volumio[20976]: info: Creating MPD Configuration file Mar 04 20:58:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+07:00" level=debug msg="obtained new client token: AADrvvWOc9xM3UDh9ztJgf/elJZXAk7B3FATnlFNce/0hWD5urIe7IZtvjQmt5f+7+C78mYf39RVOBDyzRO5KLM4nDUJVd9FCuAToq+bIenJlDfSRuIh2fjwKUqcbGrHnLYTAGKF5o/ANpVqqUVBh31iYbQ8+/grrzkK41k83Xf/5/5j2A9fKaNh9YbouLCqrrBsChtUBezjtwxJZMf9YGndhK2KE8b3EFmsw89jSprxVIROEMHs0gOARQ==" Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:00 volumio volumio[20976]: info: [1772632680711] CoreMusicLibrary::Adding element Media Servers Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:00 volumio sudo[21151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:58:00 volumio sudo[21151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:00 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:58:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:58:00 volumio systemd[1]: mpd.service: Consumed 4.287s CPU time. Mar 04 20:58:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:58:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:58:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:58:00 volumio volumio[20976]: info: UPNP Browser: Client initialized successfully Mar 04 20:58:00 volumio sudo[21155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:58:00 volumio sudo[21151]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+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" Mar 04 20:58:00 volumio sudo[21155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Mar 04 20:58:00 volumio volumio[20976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:58:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:58:00 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:58:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:58:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:58:00 volumio go-librespot[21103]: time="2026-03-04T20:58:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 04 20:58:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:58:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:58:00 volumio volumio[20976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:00 volumio volumio[20976]: info: [1772632680949] CoreMusicLibrary::Adding element Last_100 Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:58:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:00 volumio volumio[20976]: info: [1772632680969] CoreMusicLibrary::Adding element Webradio Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:00 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:58:00 volumio volumio[20976]: info: Initializing BBC Radios Mar 04 20:58:01 volumio go-librespot[21103]: time="2026-03-04T20:58:01+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:01 volumio go-librespot[21103]: time="2026-03-04T20:58:01+07:00" level=debug msg="completed challenge" Mar 04 20:58:01 volumio go-librespot[21103]: time="2026-03-04T20:58: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 " Mar 04 20:58:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:01 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:58:01 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:01 volumio volumio[20976]: info: Creating Spotify config file Mar 04 20:58:01 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:01 volumio sudo[21191]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:58:01 volumio sudo[21191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:58:01 volumio sudo[21191]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:01 volumio volumio[21071]: Starting albumart workers Mar 04 20:58:01 volumio volumio[21073]: Starting albumart workers Mar 04 20:58:01 volumio volumio[21072]: Starting albumart workers Mar 04 20:58:01 volumio volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:01 volumio volumio[20976]: info: [1772632681854] CoreMusicLibrary::Adding element YouTube Music Mar 04 20:58:01 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:01 volumio volumio[20976]: Cannot find translation for source YouTube Music Mar 04 20:58:01 volumio volumio[20976]: info: Volumio Calling Home Mar 04 20:58:01 volumio sudo[21217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Mar 04 20:58:01 volumio sudo[21217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:02 volumio sudo[21217]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:02 volumio volumio[20976]: error: Upnp client error: Error: This socket has been ended by the other party Mar 04 20:58:02 volumio volumio[20976]: info: MPD Permissions set Mar 04 20:58:02 volumio volumio[20976]: info: MPD Permissions set Mar 04 20:58:02 volumio sudo[21237]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:58:02 volumio sudo[21237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:02 volumio volumio[20976]: info: Spotify config file written Mar 04 20:58:02 volumio sudo[21239]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:58:02 volumio sudo[21239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:02 volumio sudo[21239]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:02 volumio sudo[21237]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:02 volumio sudo[21242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:58:02 volumio sudo[21242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:02 volumio volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:02 volumio go-librespot[21246]: go-librespot daemon starting... Mar 04 20:58:02 volumio sudo[21242]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio go-librespot[21254]: time="2026-03-04T20:58:02+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:02 volumio go-librespot[21254]: time="2026-03-04T20:58:02+07:00" level=debug msg="app state loaded" Mar 04 20:58:02 volumio go-librespot[21254]: time="2026-03-04T20:58:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:02 volumio volumio[20976]: info: No need to fix Spotify hosts Mar 04 20:58:03 volumio volumio[20976]: info: Volumio called home Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+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]" Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+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]" Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+07:00" level=info msg="zeroconf server listening on port 36751" Mar 04 20:58:03 volumio volumio[20976]: info: Starting Shairport Sync Mar 04 20:58:03 volumio volumio[20976]: info: Starting Shairport Sync Mar 04 20:58:03 volumio volumio[20976]: info: Starting Shairport Sync Mar 04 20:58:03 volumio sudo[21283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:58:03 volumio sudo[21283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:03 volumio sudo[21286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:58:03 volumio sudo[21286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:03 volumio sudo[21287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:58:03 volumio sudo[21287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+07:00" level=debug msg="obtained new client token: AAAt8El5AsD6aP1YuZEQnepkp9o/fLBW1aHQlUcF0elrz7LiHtBvIZm20Ptt6Z6Rb9Eu0LUHcvepvArNcaILPfPZeVNxJa92WxcuDOXfDQmcrGmRJtIh5mTCpamhMBFfUmlbzsXyQFsT8O1MgOBBayq7QL0xluyjSd4Qg3SvZdE3jCA6XUxZ8uqS+a3LKWqUZwZcUg/NTLdRUZUvMxd1v8aaUk45Hg4rinAfIlEeY0izCtSV68mnvUXXkw==" Mar 04 20:58:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:58:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:58:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:58:03 volumio systemd[1]: shairport-sync.service: Consumed 1.904s CPU time. Mar 04 20:58:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:58:03 volumio sudo[21283]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:03 volumio sudo[21293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:58:03 volumio sudo[21293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:58:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:58:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:58:03 volumio volumio[20976]: info: Shairport-Sync Started Mar 04 20:58:03 volumio volumio[20976]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58:03+07:00" level=debug msg="completed challenge" Mar 04 20:58:03 volumio volumio[20976]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:58:03 volumio volumio[20976]: SPOTIFY: BQCBWrPfxtMN8H2mucdsWPhLAnth5AgpPSu7RbS1dOABlPcA8AMy4ViypWLwzRVmktANDhKjF_imoLmPwN0ZsyBaf2N5ovkXh3tq81LPKeJ8vqooAURr06o_6yPOWHNCgFiBoXwXRTfT82gegMwGwxBPXVZEeVj0fJmOe7-_yZXcoQaEv9lisQn6OFkL4-BLkOVr95nOFmo6F7sQfvVxvggoVXGMEmhUb_8Z7mdv0_OkwpcEduxyKRckJV-AVAA2at0xWze_WeQCkfcSZNWo8zkxhO9w-AkpEi9j9VwYG-afQeP0nmspYL4H Mar 04 20:58:03 volumio volumio[20976]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:58:03 volumio volumio[20976]: info: New Spotify access token = BQCBWrPfxtMN8H2mucdsWPhLAnth5AgpPSu7RbS1dOABlPcA8AMy4ViypWLwzRVmktANDhKjF_imoLmPwN0ZsyBaf2N5ovkXh3tq81LPKeJ8vqooAURr06o_6yPOWHNCgFiBoXwXRTfT82gegMwGwxBPXVZEeVj0fJmOe7-_yZXcoQaEv9lisQn6OFkL4-BLkOVr95nOFmo6F7sQfvVxvggoVXGMEmhUb_8Z7mdv0_OkwpcEduxyKRckJV-AVAA2at0xWze_WeQCkfcSZNWo8zkxhO9w-AkpEi9j9VwYG-afQeP0nmspYL4H Mar 04 20:58:03 volumio volumio[20976]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 04 20:58:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:58:03 volumio sudo[21287]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:03 volumio volumio[20976]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:03 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:03 volumio sudo[21286]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:03 volumio go-librespot[21254]: time="2026-03-04T20:58: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 " Mar 04 20:58:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:03 volumio sudo[21293]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:03 volumio volumio[20976]: info: Shairport-Sync Started Mar 04 20:58:03 volumio volumio[20976]: info: Shairport-Sync Started Mar 04 20:58:03 volumio volumio[20976]: info: Upmpdcli Daemon Started Mar 04 20:58:04 volumio volumio[20976]: 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"} Mar 04 20:58:04 volumio volumio[20976]: info: Spotify Successfully logged in Mar 04 20:58:04 volumio volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:04 volumio volumio[20976]: info: [1772632684198] CoreMusicLibrary::Adding element Spotify Mar 04 20:58:04 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:04 volumio volumio[20976]: Cannot find translation for source YouTube Music Mar 04 20:58:04 volumio volumio[20976]: Cannot find translation for source Spotify Mar 04 20:58:04 volumio volumio[20976]: info: [yt-cast-receiver] DIAL server listening on port 8098 Mar 04 20:58:04 volumio volumio[20976]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:58:04 volumio volumio[20976]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:58:04 volumio volumio[20976]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:04 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:04 volumio volumio[20976]: info: CoreStateMachine::pushState Mar 04 20:58:04 volumio volumio[20976]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:04 volumio volumio[20976]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:05 volumio mpd[21215]: 2026-03-04T20:58:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:58:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:58:05 volumio sudo[21139]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:05 volumio sudo[21155]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:05 volumio volumio[20976]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:58:05 volumio volumio[20976]: assert.ok(self.idling) Mar 04 20:58:05 volumio volumio[20976]: error: The expression evaluated to a falsy value: Mar 04 20:58:05 volumio volumio[20976]: assert.ok(self.idling) Mar 04 20:58:05 volumio volumio[20976]: error: updateQueue error: null Mar 04 20:58:05 volumio volumio[20976]: info: MPD running with PID21215 Mar 04 20:58:05 volumio volumio[20976]: ,establishing connection Mar 04 20:58:05 volumio volumio[20976]: info: Completed starting Core Plugins Mar 04 20:58:05 volumio volumio[20976]: info: ------------------------------------------- Mar 04 20:58:05 volumio volumio[20976]: info: ----- MyVolumio plugins startup ---- Mar 04 20:58:05 volumio volumio[20976]: info: ------------------------------------------- Mar 04 20:58:05 volumio volumio[20976]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:58:05 volumio volumio[20976]: error: updateQueue error: null Mar 04 20:58:05 volumio volumio-remote-updater[675]: [2026-03-04 20:58:05] [connect] Successful connection Mar 04 20:58:05 volumio volumio-remote-updater[675]: [2026-03-04 20:58:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772632685 101 Mar 04 20:58:05 volumio volumio[20976]: 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: 2 Mar 04 20:58:06 volumio volumio[20976]: info: go-librespot daemon successfully initialized Mar 04 20:58:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 04 20:58:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:07 volumio go-librespot[21320]: go-librespot daemon starting... Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=debug msg="app state loaded" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58: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-gew1.spotify.com:80]" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+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]" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+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]" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=info msg="zeroconf server listening on port 43873" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=debug msg="obtained new client token: AAAar3LPW4Hpv0eZMjyDdVmAOdPasgVv0zb3JkGAuNaYxZudBws+T5zL/8ivs/YRkcMNLM5C2+uoDGdVXyNTt7tBFr0AoUwGyXXGRbwT0jwNbKQkOranpJEmJ1gGZdAEWmw8cr0AMusXQRWPnOACYU+UuP1+HNg7RiD0mh3qA4ZJHYcyhf/FWdwvLmc+dN0WqvaTIZZLLYKH2A6X09qiLJUyyVmU3Z6jI9wyhWhb8PmycB1Rb6tUaJf4pg==" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=debug msg="completed challenge" Mar 04 20:58:07 volumio go-librespot[21321]: time="2026-03-04T20:58:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:58:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:09 volumio volumio[20976]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:09 volumio volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:10 volumio volumio[20976]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:58:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 04 20:58:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:11 volumio go-librespot[21328]: go-librespot daemon starting... Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=debug msg="app state loaded" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+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]" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+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]" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=info msg="zeroconf server listening on port 35813" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=debug msg="obtained new client token: AAAMsUQJHf0hTyFDhaADtM6zl1eWYWJQVJ4PKwpSESw7hyQWIcTToHQWryDGZR1d9+5AFRHGAq9AE6yy4Y5SXCDpAfZ5QXYwF/n5F6z0cEhtlAH0NndQ+YL/JO7ZMof5II+/9f7Uq9X6eLQyTtpLZu30lOCCW619ShvOIGvuBR6QEldsisI5NNX0w8kxS+IsR5Ndh+Qejq8mb/BCzKEMEcTgCsSlM9204XoVZoX0d+VUaB/vddQ12+Tghw==" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58:11+07:00" level=debug msg="completed challenge" Mar 04 20:58:11 volumio go-librespot[21329]: time="2026-03-04T20:58: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 " Mar 04 20:58:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:12 volumio volumio[20976]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:12 volumio volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:58:14 volumio volumio[20976]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:58:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 04 20:58:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:15 volumio go-librespot[21350]: go-librespot daemon starting... Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=debug msg="app state loaded" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:15 volumio volumio[20976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:58:15 volumio volumio[20976]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:58:15 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:15 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:15 volumio volumio[20976]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:58:15 volumio volumio[20976]: info: MyVolumio login type: Token Mar 04 20:58:15 volumio volumio[20976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:58:15 volumio volumio[20976]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+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]" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+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]" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=info msg="zeroconf server listening on port 39079" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=debug msg="obtained new client token: AACalz3qbaLcIfZ69otG5t1G6gA1A87i3i3Voe2M/+tqnhltmOPZEBDi9TgIKsZpOMOIpRn0zFeyJy1iVj68/ch3mHlopE6HhtgT/2Uu5MEiWOZAjrn81YzHr8xPCezdiy/0LXqpgQ/5QppRxdMJyqIIcruzjQ6qJWzaeNSu0CgYIHwUcUHAw0AphY8YHF60diaA/iB7x3GGk5oYxxS5yW+84ZVptty6k7QVl2VloMAn0mzaugj+bcf/Aw==" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:15 volumio go-librespot[21351]: time="2026-03-04T20:58:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 04 20:58:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:16 volumio volumio[20976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:58:16 volumio volumio[20976]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:58:16 volumio volumio[20976]: info: Streaming services startup Mar 04 20:58:16 volumio volumio[20976]: info: Starting Streaming Daemon Mar 04 20:58:16 volumio sudo[21394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:58:16 volumio sudo[21394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:16 volumio volumio[20976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:58:16 volumio sudo[21394]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:16 volumio volumio[20976]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:16 volumio volumio[20976]: error: Cannot start Volumio Streaming Daemon Mar 04 20:58:16 volumio volumio[20976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:58:16 volumio volumio[20976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:58:16 volumio volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:17 volumio volumio[20976]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 20:58:17 volumio volumio[20976]: info: MyVolumio token set successfully Mar 04 20:58:17 volumio volumio[20976]: info: MYVOLUMIO: Adding device Mar 04 20:58:17 volumio volumio[20976]: info: MYVOLUMIO: Evaluating Server Mar 04 20:58:18 volumio volumio[20976]: info: MyVolumio status changed Mar 04 20:58:18 volumio volumio[20976]: info: Streaming services startup Mar 04 20:58:18 volumio volumio[20976]: info: Starting Streaming Daemon Mar 04 20:58:18 volumio volumio[20976]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 20:58:18 volumio volumio[20976]: info: Removing audio output: Mar 04 20:58:18 volumio volumio[20976]: info: Stoppping Tunnel 1 Mar 04 20:58:18 volumio sudo[21422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:58:18 volumio sudo[21422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:18 volumio sudo[21424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 04 20:58:18 volumio sudo[21424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio sudo[21422]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:18 volumio volumio[20976]: error: Cannot start Volumio Streaming Daemon Mar 04 20:58:18 volumio volumio[20976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:58:18 volumio volumio[20976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:18 volumio sudo[21424]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:18 volumio volumio[20976]: info: Remote SSH Stopped Mar 04 20:58:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 04 20:58:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:19 volumio go-librespot[21427]: go-librespot daemon starting... Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=debug msg="app state loaded" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58: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]" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58: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]" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58: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]" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=info msg="zeroconf server listening on port 33829" Mar 04 20:58:19 volumio volumio[20976]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=debug msg="new websocket client" Mar 04 20:58:19 volumio volumio[20976]: info: Connection to go-librespot Websocket established Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=debug msg="obtained new client token: AABdH289xH8XUyJz54pmgB/aviEHZCT5V8K4VUp3xc9mcSQjky5KFtrWUn5U6ajud839UX7f+z7cHRSnpOyInDJFfyqHY2I+FgxBVd5/GqGASKV2AEfwCPJhSU1HJVVMFEKnK6AUa7SqLR+NEzeKyEvuEWXiNPNbCsfZQIfjg2SW0nX8MN1sWqED+7LmnlW2cEbl879iU8tSK5LPtpUdcCmoOm0pEuMd6MHQPN+0Rh1c8vTnYdt2F+LPHw==" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58:19+07:00" level=debug msg="completed challenge" Mar 04 20:58:19 volumio go-librespot[21428]: time="2026-03-04T20:58: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 " Mar 04 20:58:19 volumio volumio[20976]: info: Connection to go-librespot Websocket closed Mar 04 20:58:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:20 volumio volumio[20976]: info: Setting Geolocation for MyVolumio to as1 Mar 04 20:58:20 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:20 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:20 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:21 volumio volumio[20976]: info: Updating MyVolumio device info Mar 04 20:58:21 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:21 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:21 volumio volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:21 volumio volumio[20976]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 04 20:58:22 volumio volumio[20976]: info: Getting Spotify volume Mar 04 20:58:22 volumio volumio[20976]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:58:22 volumio volumio[20976]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:22 volumio volumio[20976]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 20:58:22 volumio volumio[20976]: errno: -111, Mar 04 20:58:22 volumio volumio[20976]: code: 'ECONNREFUSED', Mar 04 20:58:22 volumio volumio[20976]: syscall: 'connect', Mar 04 20:58:22 volumio volumio[20976]: address: '127.0.0.1', Mar 04 20:58:22 volumio volumio[20976]: port: 9879, Mar 04 20:58:22 volumio volumio[20976]: response: undefined Mar 04 20:58:22 volumio volumio[20976]: } Mar 04 20:58:22 volumio volumio[20976]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:58:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 04 20:58:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:23 volumio go-librespot[21462]: go-librespot daemon starting... Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=debug msg="app state loaded" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:23 volumio sudo[21471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:57' Mar 04 20:58:23 volumio sudo[21471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:23 volumio sudo[21471]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58: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]" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58: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]" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58: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]" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=info msg="zeroconf server listening on port 39347" Mar 04 20:58:23 volumio volumio-remote-updater[675]: [2026-03-04 20:58:23] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 20:58:23 volumio volumio-remote-updater[675]: [2026-03-04 20:58:23] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 20:58:23 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:23 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 20:58:23 volumio systemd[1]: volumio.service: Consumed 33.769s CPU time. Mar 04 20:58:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:58:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=debug msg="obtained new client token: AADbaOuOqQUbGYzaVlN+tARcUt5guAwel2DpE6K69WS79AUTzoXMQIzcW1ives7XKe0QTynCe5pkxE4DavuLplf+21Q1CZ5iRvLVqis8StSI8vwZkx7E1sxfcUYLjHbtLNPfxRky6r/K0stxYUizqbSUydK0urURuCiRJatAKf0Shf/+PinCFnP2ggdW+aP522Dlycnp1ugBgFXNB9yqrsomrblLpp3ACo7YkCXWWIVDDc7DDDBHCkiQRA==" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:23 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 34. Mar 04 20:58:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:58:23 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 20:58:23 volumio systemd[1]: volumio.service: Consumed 33.769s CPU time. Mar 04 20:58:23 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58:23+07:00" level=debug msg="completed challenge" Mar 04 20:58:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:58:23 volumio go-librespot[21463]: time="2026-03-04T20:58: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 " Mar 04 20:58:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:25 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:25 volumio volumio[21484]: info: ----- Volumio3 ---- Mar 04 20:58:25 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:25 volumio volumio[21484]: info: ----- System startup ---- Mar 04 20:58:25 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:26 volumio volumio[21484]: info: MYVOLUMIO Environment detected Mar 04 20:58:26 volumio volumio[21484]: info: Plugin folders cleanup Mar 04 20:58:26 volumio volumio[21484]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category audio_interface Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category miscellanea Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category music_service Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category plugins.json Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category system_controller Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category user_interface Mar 04 20:58:26 volumio volumio[21484]: info: Scanning into folder /data/plugins/ Mar 04 20:58:26 volumio volumio[21484]: info: Scanning category music_service Mar 04 20:58:26 volumio volumio[21484]: info: Plugin folders cleanup completed Mar 04 20:58:26 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:26 volumio volumio[21484]: info: ----- Core plugins startup ---- Mar 04 20:58:26 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:26 volumio volumio[21484]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:58:26 volumio volumio[21484]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:58:26 volumio volumio[21484]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:58:26 volumio volumio[21484]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:58:26 volumio volumio[21484]: info: Loading plugins from folder /data/plugins/ Mar 04 20:58:26 volumio volumio[21484]: info: Loading plugin "system"... Mar 04 20:58:26 volumio volumio[21484]: info: Loading plugin "appearance"... Mar 04 20:58:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 04 20:58:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:27 volumio go-librespot[21511]: go-librespot daemon starting... Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=debug msg="app state loaded" Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58: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]" Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58: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]" Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58: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]" Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=info msg="zeroconf server listening on port 39975" Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "network"... Mar 04 20:58:27 volumio volumio[21484]: info: Refreshing Cached IP Addresses Mar 04 20:58:27 volumio sudo[21521]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:58:27 volumio sudo[21521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:27 volumio sudo[21523]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:58:27 volumio sudo[21523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:27 volumio sudo[21521]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:27 volumio sudo[21523]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "services"... Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "alsa_controller"... Mar 04 20:58:27 volumio sudo[21531]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:58:27 volumio sudo[21531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=debug msg="obtained new client token: AAD4/ZhuW5dsZaxnygTYpVuM0UW3cIeJyoWO0vnv25u52Da1NsJi6tQUhATwyI7siQ90tnHVPYpPDhko+sya6XkmTt1l/n6FBJTbWct/q8BLEf1VQCv7yQdZYUyRZhReD0gaY/5iK39d33L5FJWxmhiAIf2zOrBJGY3CADdR5kxGK56F2B9nY1x0znvNnA7n4narYSYppbFmzuMjK9ab3i6JeP0pfWR/A4PMqDuKJ/q9OCRVoHvt8bFNhg==" Mar 04 20:58:27 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "wizard"... Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "networkfs"... Mar 04 20:58:27 volumio volumio[21484]: info: Starting Udev Watcher for removable devices Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:27 volumio volumio[21484]: info: Ignoring mount for partition: boot Mar 04 20:58:27 volumio volumio[21484]: info: Ignoring mount for partition: volumio Mar 04 20:58:27 volumio volumio[21484]: info: Ignoring mount for partition: volumio_data Mar 04 20:58:27 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "upnp"... Mar 04 20:58:27 volumio volumio[21484]: info: [1772632707772] Starting Upmpd Daemon Mar 04 20:58:27 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "my_music"... Mar 04 20:58:27 volumio volumio[21484]: info: Loading plugin "mpd"... Mar 04 20:58:27 volumio go-librespot[21512]: time="2026-03-04T20:58:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 04 20:58:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:28 volumio volumio[21484]: info: Loading plugin "upnp_browser"... Mar 04 20:58:28 volumio volumio-remote-updater[675]: [2026-03-04 20:58:28] [connect] Successful connection Mar 04 20:58:29 volumio volumio[21484]: info: Starting UPNP Browser Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "alarm-clock"... Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "airplay_emulation"... Mar 04 20:58:29 volumio volumio[21484]: info: Starting Shairport Sync Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "last_100"... Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "webradio"... Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "i2s_dacs"... Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "volumiodiscovery"... Mar 04 20:58:29 volumio volumio[21484]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:58:29 volumio volumio[21484]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:58:29 volumio volumio[21484]: *** WARNING *** For more information see Mar 04 20:58:29 volumio volumio[21484]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:58:29 volumio volumio[21484]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:58:29 volumio volumio[21484]: *** WARNING *** For more information see Mar 04 20:58:29 volumio node[21484]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:58:29 volumio node[21484]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:58:29 volumio node[21484]: *** WARNING *** For more information see Mar 04 20:58:29 volumio node[21484]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:58:29 volumio node[21484]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:58:29 volumio node[21484]: *** WARNING *** For more information see Mar 04 20:58:29 volumio volumio[21484]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:58:29 volumio volumio[21484]: info: Discovery: Started advertising with name: Volumio Mar 04 20:58:29 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:58:29 volumio volumio[21484]: info: Loading plugin "spop"... Mar 04 20:58:30 volumio sudo[21531]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 04 20:58:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:31 volumio volumio[21484]: info: Loading plugin "ytcr"... Mar 04 20:58:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:31 volumio go-librespot[21562]: go-librespot daemon starting... Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=debug msg="app state loaded" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+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]" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+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]" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+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]" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=info msg="zeroconf server listening on port 35611" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=debug msg="obtained new client token: AAB9951NdkXrpRrH25SmCK5htTQf4HGEjQWt1BbUoITuMx4zoH8hesSuMNJJ2IaX7U3wtjcxY4wpesW2SO8k2GqaaFRbhuSeQ/9rSIRkwH4ovCxiHNh3Riy7JvyKW8sC12W0PkCOWP8SM7U/CbbbUOHNKEtJP9kyEcGbwwEli5+oN5eH/OeAk+Y98hOXAcav8MrxEBwPWpXgq2BDjpMntTsM185mnVaQTJ7nWfKgvo2v1yyC1LkJqdVH3g==" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:31 volumio go-librespot[21568]: time="2026-03-04T20:58:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 04 20:58:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:32 volumio volumio[21484]: info: Loading plugin "ytmusic"... Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "outputs"... Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "albumart"... Mar 04 20:58:33 volumio volumio[21484]: info: Plugin example_plugin is not enabled Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "inputs"... Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "updater_comm"... Mar 04 20:58:33 volumio volumio[21484]: info: Plugin mpdemulation is not enabled Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "rest_api"... Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "websocket"... Mar 04 20:58:33 volumio volumio[21484]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:58:33 volumio volumio[21484]: info: Loading plugin "RoonBridge"... Mar 04 20:58:33 volumio volumio[21484]: info: Applying required configuration parameters for plugin RoonBridge Mar 04 20:58:33 volumio volumio[21484]: info: Loading i18n strings for locale en Mar 04 20:58:33 volumio volumio[21484]: Updating browse sources language Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:33 volumio volumio[21594]: Forking 3 albumart workers Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::initPlayerControls Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:58:33 volumio volumio[21484]: Express server listening on port 3000 Mar 04 20:58:33 volumio volumio[21484]: [Metrics] WebUI: 8s 670.10ms Mar 04 20:58:33 volumio volumio[21484]: info: CoreStateMachine::resetVolumioState Mar 04 20:58:33 volumio volumio[21484]: info: CoreStateMachine::getcurrentVolume Mar 04 20:58:33 volumio volumio[21484]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:58:33 volumio volumio[21484]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: Reloading queue from file Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::setRepeat null single undefined Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::pushState Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::setRandom null Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::pushState Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:34 volumio volumio[21484]: info: Setting Device type: Raspberry PI Mar 04 20:58:34 volumio volumio[21484]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::pushState Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::updateTrackBlock Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrackBlock Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:58:34 volumio volumio[21484]: info: Completed loading Core Plugins Mar 04 20:58:34 volumio volumio[21484]: info: Preparing to generate the ALSA configuration file Mar 04 20:58:34 volumio volumio[21484]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:58:34 volumio volumio[21484]: info: Discovery: Found device Volumio Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:34 volumio volumio[21484]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:58:34 volumio volumio[21484]: info: Discovery: Found device Volumio Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:34 volumio volumio[21484]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:58:34 volumio volumio[21484]: info: CoreStateMachine::pushState Mar 04 20:58:34 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:34 volumio volumio[21484]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:58:34 volumio volumio[21484]: info: Output device has changed, restarting MPD Mar 04 20:58:34 volumio volumio[21484]: info: Output device has changed, restarting Shairport Sync Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:58:34 volumio volumio[21484]: info: ___________ START PLUGINS ___________ Mar 04 20:58:34 volumio sudo[21650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:58:34 volumio sudo[21648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:58:34 volumio volumio[21484]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:58:34 volumio volumio[21484]: info: Creating MPD Configuration file Mar 04 20:58:34 volumio sudo[21648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:34 volumio sudo[21650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:34 volumio sudo[21648]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:34 volumio volumio[21484]: info: [1772632714462] CoreMusicLibrary::Adding element Media Servers Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:34 volumio volumio[21484]: info: UPNP Browser: Client initialized successfully Mar 04 20:58:34 volumio sudo[21659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:58:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:58:34 volumio sudo[21659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:34 volumio sudo[21659]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:34 volumio sudo[21660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:58:34 volumio sudo[21660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:34 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:58:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:58:34 volumio systemd[1]: mpd.service: Consumed 4.299s CPU time. Mar 04 20:58:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:58:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:58:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:58:34 volumio volumio[21484]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:58:34 volumio volumio[21484]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:34 volumio volumio[21484]: info: [1772632714701] CoreMusicLibrary::Adding element Last_100 Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:34 volumio volumio[21484]: info: [1772632714710] CoreMusicLibrary::Adding element Webradio Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:58:34 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:58:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:58:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:58:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:58:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:58:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:58:34 volumio volumio[21484]: info: Initializing BBC Radios Mar 04 20:58:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:34 volumio volumio[21484]: info: Creating Spotify config file Mar 04 20:58:34 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 04 20:58:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:35 volumio sudo[21674]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:58:35 volumio sudo[21674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:58:35 volumio sudo[21674]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:35 volumio go-librespot[21688]: go-librespot daemon starting... Mar 04 20:58:35 volumio go-librespot[21690]: time="2026-03-04T20:58:35+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:35 volumio volumio[21604]: Starting albumart workers Mar 04 20:58:35 volumio volumio[21484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:35 volumio volumio[21484]: info: [1772632715593] CoreMusicLibrary::Adding element YouTube Music Mar 04 20:58:35 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:35 volumio volumio[21484]: Cannot find translation for source YouTube Music Mar 04 20:58:35 volumio go-librespot[21690]: time="2026-03-04T20:58:35+07:00" level=info msg="zeroconf server listening on port 43361" Mar 04 20:58:35 volumio volumio[21484]: info: Volumio Calling Home Mar 04 20:58:35 volumio volumio[21605]: Starting albumart workers Mar 04 20:58:35 volumio sudo[21699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Mar 04 20:58:35 volumio sudo[21699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:35 volumio sudo[21699]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:36 volumio volumio[21606]: Starting albumart workers Mar 04 20:58:36 volumio volumio[21484]: info: MPD Permissions set Mar 04 20:58:36 volumio volumio[21484]: info: MPD Permissions set Mar 04 20:58:36 volumio volumio[21484]: info: Volumio called home Mar 04 20:58:36 volumio volumio[21484]: info: Spotify config file written Mar 04 20:58:36 volumio sudo[21706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:58:36 volumio sudo[21706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:36 volumio volumio[21484]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 20:58:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 20:58:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio go-librespot[21713]: go-librespot daemon starting... Mar 04 20:58:36 volumio sudo[21706]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio go-librespot[21716]: time="2026-03-04T20:58:36+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:36 volumio go-librespot[21716]: time="2026-03-04T20:58:36+07:00" level=debug msg="app state loaded" Mar 04 20:58:36 volumio go-librespot[21716]: time="2026-03-04T20:58:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:58:36 volumio volumio[21484]: info: No need to fix Spotify hosts Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=info msg="zeroconf server listening on port 44111" Mar 04 20:58:37 volumio volumio[21484]: info: Starting Shairport Sync Mar 04 20:58:37 volumio volumio[21484]: info: Starting Shairport Sync Mar 04 20:58:37 volumio volumio[21484]: info: Starting Shairport Sync Mar 04 20:58:37 volumio sudo[21746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:58:37 volumio sudo[21746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="obtained new client token: AABk2ijzfk5LxHN7zculikgRsvRS3La9b1xESt+AlD7EYNH3tCfjfBCO91onmXrmys3hWiwGsR70B/4THKVDzsoITISvx0BUg4uQsrlthN2msLB+vVsAOdWbOFiLh6xwk5geSyk+IjVG9NeoSzbDNBBY0HUoA1Fk4VWsHaPhYk669UD+Y7yuFoI6EFSlLbkm2n8jZyTJX8OT5Ucr/GL51iANzh7lnXpA2rCu4jO277+UQYf2jmA5WFg5kg==" Mar 04 20:58:37 volumio sudo[21748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:58:37 volumio sudo[21750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:58:37 volumio sudo[21750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:37 volumio sudo[21748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Mar 04 20:58:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:58:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:58:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:58:37 volumio systemd[1]: shairport-sync.service: Consumed 1.873s CPU time. Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Mar 04 20:58:37 volumio volumio[21484]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:37 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:37 volumio volumio[21484]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:58:37 volumio volumio[21484]: SPOTIFY: BQCUFM4TiOQu7TW-QH0h972SXKt7_2_pVoq7Ir-Epe8MQvOoi7KPMYN53kuUyzsOm2RQEKBpPL3luqq6A82ZzElbzYta8DI5G4VYx_55nz67mCeM8WqT7cr1MecEPSC5_B4_FCB6mi2IZCF-Bt1qdIEpYosmmu-n8t2wRKQbgWFtmVAh0Pw10m8_ODMcRHfkURIFKkcyKQbgpELaScW-zhsp8Yw_571P3KvnnufIqcUTH-kThlB1-oZJAaksuE1TjNGVPC0Gjed2KcWOwBqA4hJwOvnSMrhEH7ZNTXg4h1rPHJ_MHya1rRM0 Mar 04 20:58:37 volumio volumio[21484]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:58:37 volumio volumio[21484]: info: New Spotify access token = BQCUFM4TiOQu7TW-QH0h972SXKt7_2_pVoq7Ir-Epe8MQvOoi7KPMYN53kuUyzsOm2RQEKBpPL3luqq6A82ZzElbzYta8DI5G4VYx_55nz67mCeM8WqT7cr1MecEPSC5_B4_FCB6mi2IZCF-Bt1qdIEpYosmmu-n8t2wRKQbgWFtmVAh0Pw10m8_ODMcRHfkURIFKkcyKQbgpELaScW-zhsp8Yw_571P3KvnnufIqcUTH-kThlB1-oZJAaksuE1TjNGVPC0Gjed2KcWOwBqA4hJwOvnSMrhEH7ZNTXg4h1rPHJ_MHya1rRM0 Mar 04 20:58:37 volumio volumio[21484]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 04 20:58:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:58:37 volumio sudo[21746]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:37 volumio sudo[21748]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:37 volumio sudo[21750]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58:37+07:00" level=debug msg="completed challenge" Mar 04 20:58:37 volumio volumio[21484]: info: Shairport-Sync Started Mar 04 20:58:37 volumio volumio[21484]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:58:37 volumio volumio[21484]: info: Shairport-Sync Started Mar 04 20:58:37 volumio volumio[21484]: info: Shairport-Sync Started Mar 04 20:58:37 volumio go-librespot[21716]: time="2026-03-04T20:58: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 " Mar 04 20:58:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:37 volumio sudo[21786]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:58:37 volumio sudo[21786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:37 volumio sudo[21786]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:37 volumio sudo[21787]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:58:37 volumio sudo[21787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:37 volumio sudo[21787]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:38 volumio sudo[21791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:58:38 volumio sudo[21791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:38 volumio sudo[21791]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:38 volumio volumio[21484]: 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"} Mar 04 20:58:38 volumio volumio[21484]: info: Spotify Successfully logged in Mar 04 20:58:38 volumio volumio[21484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:58:38 volumio volumio[21484]: info: [1772632718114] CoreMusicLibrary::Adding element Spotify Mar 04 20:58:38 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:58:38 volumio volumio[21484]: Cannot find translation for source YouTube Music Mar 04 20:58:38 volumio volumio[21484]: Cannot find translation for source Spotify Mar 04 20:58:38 volumio volumio[21484]: info: Upmpdcli Daemon Started Mar 04 20:58:38 volumio volumio[21484]: info: [yt-cast-receiver] DIAL server listening on port 8098 Mar 04 20:58:38 volumio volumio[21484]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:58:38 volumio volumio[21484]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:58:38 volumio volumio[21484]: info: CoreCommandRouter::volumioGetState Mar 04 20:58:38 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:38 volumio volumio[21484]: info: CoreStateMachine::pushState Mar 04 20:58:38 volumio volumio[21484]: info: CorePlayQueue::getTrack 0 Mar 04 20:58:38 volumio volumio[21484]: info: CoreCommandRouter::volumioPushState Mar 04 20:58:39 volumio mpd[21691]: 2026-03-04T20:58:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:58:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:58:39 volumio sudo[21650]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:39 volumio sudo[21660]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:39 volumio volumio[21484]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:58:39 volumio volumio[21484]: assert.ok(self.idling) Mar 04 20:58:39 volumio volumio[21484]: error: The expression evaluated to a falsy value: Mar 04 20:58:39 volumio volumio[21484]: assert.ok(self.idling) Mar 04 20:58:39 volumio volumio[21484]: info: MPD running with PID21691 Mar 04 20:58:39 volumio volumio[21484]: ,establishing connection Mar 04 20:58:39 volumio volumio[21484]: error: updateQueue error: null Mar 04 20:58:39 volumio volumio[21484]: info: Completed starting Core Plugins Mar 04 20:58:39 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:39 volumio volumio[21484]: info: ----- MyVolumio plugins startup ---- Mar 04 20:58:39 volumio volumio[21484]: info: ------------------------------------------- Mar 04 20:58:39 volumio volumio[21484]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:58:39 volumio volumio[21484]: error: updateQueue error: null Mar 04 20:58:40 volumio volumio[21484]: info: go-librespot daemon successfully initialized Mar 04 20:58:40 volumio volumio-remote-updater[675]: [2026-03-04 20:58:40] [connect] Successful connection Mar 04 20:58:40 volumio volumio-remote-updater[675]: [2026-03-04 20:58:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772632720 101 Mar 04 20:58:40 volumio volumio[21484]: 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: 2 Mar 04 20:58:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 20:58:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:41 volumio go-librespot[21801]: go-librespot daemon starting... Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=debug msg="app state loaded" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+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]" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+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]" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=info msg="zeroconf server listening on port 33597" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=debug msg="obtained new client token: AACmX6boRAIMFXD2aX51uMsdwLkXc6QBBzwF2ZSBcIuzRAlZ+BQ3KDxtwxv0FaLxSaBnVADJ9I6WW+6a9Y5EgcZtZDhgK3HyVjKBOd+BslKWXWnw4gzGxv7RChCSU17XjLOyEgDGlXXJBNAU2YrN4/eRJiEceo2yxSiGV0QR2LFSdGXng7LrrEZN3t5kuaWRAOSI3iOdHAJ1qjoO5J013W4Z7nvRTVrOJTDPRs5v39a904wyYp+AX75gDA==" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58:41+07:00" level=debug msg="completed challenge" Mar 04 20:58:41 volumio go-librespot[21802]: time="2026-03-04T20:58: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 " Mar 04 20:58:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:43 volumio volumio[21484]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:43 volumio volumio[21484]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:44 volumio volumio[21484]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:58:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 20:58:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:45 volumio go-librespot[21811]: go-librespot daemon starting... Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="app state loaded" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=info msg="zeroconf server listening on port 40099" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="obtained new client token: AAASn8G4ISMotT5vCCPZhx4X8PPlGxLPKpkRnM5EjNfbzYHNKcL3Fx4UxzjU34afCs60IAj61i2f4HVmKuay91ojVSqHUEz/WKWot1wTgkPY3+S43fsT2L7X2Uxptqc+IJglvXNXVs30JMPRGPV5vVlARopkzgps957xhjU3/c+WIPXsLTOiej08yy4M2fXoA69igoqS3+i9DMmKW1Dg6usk/jCwysi2v7aPWCEb0PAmqORv0b5yx+TZ6w==" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58:45+07:00" level=debug msg="completed challenge" Mar 04 20:58:45 volumio go-librespot[21812]: time="2026-03-04T20:58: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 " Mar 04 20:58:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:46 volumio volumio[21484]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:46 volumio volumio[21484]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:58:48 volumio volumio[21484]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:58:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 20:58:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:49 volumio volumio[21484]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:58:49 volumio volumio[21484]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:58:49 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:49 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:49 volumio volumio[21484]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:58:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:49 volumio go-librespot[21872]: go-librespot daemon starting... Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=debug msg="app state loaded" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:49 volumio volumio[21484]: info: MyVolumio login type: Token Mar 04 20:58:49 volumio volumio[21484]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:58:49 volumio volumio[21484]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58: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-gew4.spotify.com:80]" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+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]" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+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]" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=info msg="zeroconf server listening on port 43881" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=debug msg="obtained new client token: AADTsci8aOn7kEuD/X6auO+IXvUAjkBARtydliUduvpencNoy99U4Lf7AvqkB/TvjQUzfKP7IxFXdDD+1Jl5IkrYAJ0Wvj9AkrHe5m0DRsg+ujlEXCdlZXTMv5prKnVa+gqdfNrhYYgfdSmPRv1gwfT69MLu+DS8aUlyYbSPyvY7cpZAXTV5S/WPROFbggUqb49NTKTAKBbetk+gxGBLJp9k+rMOSjB+zGVs+kG50DmnWYk5LfX+XQDmAg==" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+07:00" level=debug msg="completed challenge" Mar 04 20:58:49 volumio go-librespot[21873]: time="2026-03-04T20:58:49+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 " Mar 04 20:58:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:50 volumio volumio[21484]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:58:50 volumio volumio[21484]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:58:50 volumio volumio[21484]: info: Streaming services startup Mar 04 20:58:50 volumio volumio[21484]: info: Starting Streaming Daemon Mar 04 20:58:50 volumio sudo[21881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:58:50 volumio sudo[21881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:50 volumio volumio[21484]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:58:50 volumio sudo[21881]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:50 volumio volumio[21484]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:50 volumio volumio[21484]: error: Cannot start Volumio Streaming Daemon Mar 04 20:58:50 volumio volumio[21484]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:58:50 volumio volumio[21484]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:58:50 volumio volumio[21484]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:50 volumio volumio[21484]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 20:58:51 volumio volumio[21484]: info: MyVolumio token set successfully Mar 04 20:58:51 volumio volumio[21484]: info: MYVOLUMIO: Adding device Mar 04 20:58:51 volumio volumio[21484]: info: MYVOLUMIO: Evaluating Server Mar 04 20:58:52 volumio volumio[21484]: info: MyVolumio status changed Mar 04 20:58:52 volumio volumio[21484]: info: Streaming services startup Mar 04 20:58:52 volumio volumio[21484]: info: Starting Streaming Daemon Mar 04 20:58:52 volumio volumio[21484]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 20:58:52 volumio volumio[21484]: info: Removing audio output: Mar 04 20:58:52 volumio volumio[21484]: info: Stoppping Tunnel 1 Mar 04 20:58:52 volumio sudo[21910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:58:52 volumio sudo[21910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:52 volumio sudo[21912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 04 20:58:52 volumio sudo[21912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio sudo[21910]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:52 volumio volumio[21484]: error: Cannot start Volumio Streaming Daemon Mar 04 20:58:52 volumio volumio[21484]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:58:52 volumio volumio[21484]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:58:52 volumio sudo[21912]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:52 volumio volumio[21484]: info: Remote SSH Stopped Mar 04 20:58:52 volumio volumio[21484]: info: Setting Geolocation for MyVolumio to as1 Mar 04 20:58:52 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:52 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:52 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 20:58:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:53 volumio go-librespot[21915]: go-librespot daemon starting... Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="app state loaded" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:53 volumio volumio[21484]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 04 20:58:53 volumio volumio[21484]: info: Initializing connection to go-librespot Websocket Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="new websocket client" Mar 04 20:58:53 volumio volumio[21484]: info: Connection to go-librespot Websocket established Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=info msg="zeroconf server listening on port 33531" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="obtained new client token: AAAth9//ZOt+kxcylY+A1TQuKycBWUWTqCMnp+r+kbWXU0D9ZamuwQj2dBKdWWLrIsSk1/nNOL5u3ZC6kIXID75mUE4aNytwur/ChPKakR3Bcoi7EsdZt1i8EzTXlSi2lgM624czNJjQRGxA91OyePk6/77LBsrdlo0kn9SrzzlMWhFXkX6mnqT0KgfumAWCjHh+U0pwgvLyUk3VpOTA1R5VP/fRX0NzdMm0M88rYJ1U4OzqwFKJZj6vjA==" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+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" Mar 04 20:58:53 volumio volumio[21484]: info: Updating MyVolumio device info Mar 04 20:58:53 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:53 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:53 volumio volumio[21484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=debug msg="completed challenge" Mar 04 20:58:53 volumio go-librespot[21916]: time="2026-03-04T20:58:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:58:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:53 volumio volumio[21484]: info: Connection to go-librespot Websocket closed Mar 04 20:58:54 volumio volumio[21484]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 04 20:58:56 volumio volumio[21484]: info: Getting Spotify volume Mar 04 20:58:56 volumio volumio[21484]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:58:56 volumio volumio[21484]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:58:56 volumio volumio[21484]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 20:58:56 volumio volumio[21484]: errno: -111, Mar 04 20:58:56 volumio volumio[21484]: code: 'ECONNREFUSED', Mar 04 20:58:56 volumio volumio[21484]: syscall: 'connect', Mar 04 20:58:56 volumio volumio[21484]: address: '127.0.0.1', Mar 04 20:58:56 volumio volumio[21484]: port: 9879, Mar 04 20:58:56 volumio volumio[21484]: response: undefined Mar 04 20:58:56 volumio volumio[21484]: } Mar 04 20:58:56 volumio volumio[21484]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:58:56 volumio sudo[21938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:57' Mar 04 20:58:56 volumio sudo[21938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:58:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 20:58:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:58:57 volumio go-librespot[21940]: go-librespot daemon starting... Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=debug msg="app state loaded" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:58:57 volumio sudo[21938]: pam_unix(sudo:session): session closed for user root Mar 04 20:58:57 volumio volumio-remote-updater[675]: [2026-03-04 20:58:57] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 20:58:57 volumio volumio-remote-updater[675]: [2026-03-04 20:58:57] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 20:58:57 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:57 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 20:58:57 volumio systemd[1]: volumio.service: Consumed 31.783s CPU time. Mar 04 20:58:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:58:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+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]" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+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]" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=info msg="zeroconf server listening on port 34307" Mar 04 20:58:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 35. Mar 04 20:58:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:58:57 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 20:58:57 volumio systemd[1]: volumio.service: Consumed 31.783s CPU time. Mar 04 20:58:57 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 20:58:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=debug msg="obtained new client token: AADSVG5OhJ4oLKwN99WtYwUOg665nD4D49uZfjQX8s2thrFYfsPxnYiH7OihwEmiaLG9Y/xZe1TiJGNo103djXbh02HHP+fhwL7ejKtbvebvmLDKL0lv8PYJQPXB7qFHvKgXIHhoQHLGuSOeCaOjMVZgP2Zh7T2jKjqsgF7G//K60e/tCRqlTflYKFVK2Uoi32xK/yLf4+tXuXz6baEqSGMDzW6m7bauzEwXvx10cM3hnrlbY8MkMrWXCQ==" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=debug msg="completed keyexchange" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58:57+07:00" level=debug msg="completed challenge" Mar 04 20:58:57 volumio go-librespot[21941]: time="2026-03-04T20:58: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 " Mar 04 20:58:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:58:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:58:59 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:58:59 volumio volumio[21958]: info: ----- Volumio3 ---- Mar 04 20:58:59 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:58:59 volumio volumio[21958]: info: ----- System startup ---- Mar 04 20:58:59 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:59:00 volumio volumio[21958]: info: MYVOLUMIO Environment detected Mar 04 20:59:00 volumio volumio[21958]: info: Plugin folders cleanup Mar 04 20:59:00 volumio volumio[21958]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category audio_interface Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category miscellanea Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category music_service Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category plugins.json Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category system_controller Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category user_interface Mar 04 20:59:00 volumio volumio[21958]: info: Scanning into folder /data/plugins/ Mar 04 20:59:00 volumio volumio[21958]: info: Scanning category music_service Mar 04 20:59:00 volumio volumio[21958]: info: Plugin folders cleanup completed Mar 04 20:59:00 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:59:00 volumio volumio[21958]: info: ----- Core plugins startup ---- Mar 04 20:59:00 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:59:00 volumio volumio[21958]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:59:00 volumio volumio[21958]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:59:00 volumio volumio[21958]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:59:00 volumio volumio[21958]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:59:00 volumio volumio[21958]: info: Loading plugins from folder /data/plugins/ Mar 04 20:59:00 volumio volumio[21958]: info: Loading plugin "system"... Mar 04 20:59:00 volumio volumio[21958]: info: Loading plugin "appearance"... Mar 04 20:59:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 20:59:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:01 volumio go-librespot[21985]: go-librespot daemon starting... Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+07:00" level=debug msg="app state loaded" Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "network"... Mar 04 20:59:01 volumio volumio[21958]: info: Refreshing Cached IP Addresses Mar 04 20:59:01 volumio sudo[22004]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:59:01 volumio sudo[22004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:01 volumio sudo[22004]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:01 volumio sudo[22009]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:59:01 volumio sudo[22009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:01 volumio sudo[22009]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "services"... Mar 04 20:59:01 volumio sudo[22021]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:59:01 volumio sudo[22021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "alsa_controller"... Mar 04 20:59:01 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "wizard"... Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "networkfs"... Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+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]" Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+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]" Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+07:00" level=info msg="zeroconf server listening on port 38091" Mar 04 20:59:01 volumio volumio[21958]: info: Starting Udev Watcher for removable devices Mar 04 20:59:01 volumio volumio[21958]: info: Ignoring mount for partition: boot Mar 04 20:59:01 volumio volumio[21958]: info: Ignoring mount for partition: volumio Mar 04 20:59:01 volumio volumio[21958]: info: Ignoring mount for partition: volumio_data Mar 04 20:59:01 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "upnp"... Mar 04 20:59:01 volumio volumio[21958]: info: [1772632741565] Starting Upmpd Daemon Mar 04 20:59:01 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "my_music"... Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "mpd"... Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+07:00" level=debug msg="obtained new client token: AAAZm/FyZTs5SVF0Xy1ikWolYr+v4XVTDRRgpFZlUrYZt3Ac3mmqUtmT1R7ZXRAdh6nDv+aBKgSgzc21szzW5n74s1eD6wR1e+SL8NLhKWsd7gcreFzA/bBstPhMqygSJKeGJpRUqKEKA+3oiKZbqVgqwDAJvLA9NDdHBZzKDyBjCMxS+PDnwR20KwcgjM1LR6aNZUXvBycQZyLPBgdRegF+3NgZOG4K+hNsKf+tJMyIZfZZq8I1PNzUow==" Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59: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" Mar 04 20:59:01 volumio volumio[21958]: info: Loading plugin "upnp_browser"... Mar 04 20:59:01 volumio go-librespot[21986]: time="2026-03-04T20:59:01+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Mar 04 20:59:02 volumio go-librespot[21986]: time="2026-03-04T20:59:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Mar 04 20:59:02 volumio go-librespot[21986]: time="2026-03-04T20:59:02+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:02 volumio go-librespot[21986]: time="2026-03-04T20:59:02+07:00" level=debug msg="completed challenge" Mar 04 20:59:02 volumio volumio-remote-updater[675]: [2026-03-04 20:59:02] [connect] Successful connection Mar 04 20:59:02 volumio go-librespot[21986]: time="2026-03-04T20:59:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:59:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:03 volumio volumio[21958]: info: Starting UPNP Browser Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "alarm-clock"... Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "airplay_emulation"... Mar 04 20:59:03 volumio volumio[21958]: info: Starting Shairport Sync Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "last_100"... Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "webradio"... Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "i2s_dacs"... Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "volumiodiscovery"... Mar 04 20:59:03 volumio volumio[21958]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:03 volumio volumio[21958]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:03 volumio volumio[21958]: *** WARNING *** For more information see Mar 04 20:59:03 volumio volumio[21958]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:03 volumio volumio[21958]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:03 volumio volumio[21958]: *** WARNING *** For more information see Mar 04 20:59:03 volumio node[21958]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:03 volumio node[21958]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:03 volumio node[21958]: *** WARNING *** For more information see Mar 04 20:59:03 volumio node[21958]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:03 volumio node[21958]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:03 volumio node[21958]: *** WARNING *** For more information see Mar 04 20:59:03 volumio volumio[21958]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:59:03 volumio volumio[21958]: info: Discovery: Started advertising with name: Volumio Mar 04 20:59:03 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:59:03 volumio volumio[21958]: info: Loading plugin "spop"... Mar 04 20:59:03 volumio sudo[22021]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:04 volumio volumio[21958]: info: Loading plugin "ytcr"... Mar 04 20:59:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 20:59:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:05 volumio go-librespot[22074]: go-librespot daemon starting... Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+07:00" level=debug msg="app state loaded" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+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]" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+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]" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+07:00" level=info msg="zeroconf server listening on port 46065" Mar 04 20:59:05 volumio go-librespot[22075]: time="2026-03-04T20:59:05+07:00" level=debug msg="obtained new client token: AAAyK1m7DXDkhLrB2j4DbQGpd5S/7D5gGXWrvKB6EGdoBWrGt1bKrFMhW69Gd5lyccxgn5iliO9wcFQ4AZ3FGYKvI+/5aNcV+PwLR0HCfdQTiSM8iCURmn6UXCccvN5Ah/lJ0OfYFY+/EBl2ZnX/Jp0Jh9A+HSPKtQ4skZTopaMwCHSToJ6/e4p4GXtcR9iWx3l+i27UpCFqGZH8+qLOegM5c2OsAwDvr2/plyzNVzdbAL/iD/dFtqMTGw==" Mar 04 20:59:06 volumio go-librespot[22075]: time="2026-03-04T20:59:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:06 volumio go-librespot[22075]: time="2026-03-04T20:59:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 04 20:59:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:06 volumio volumio[21958]: info: Loading plugin "ytmusic"... Mar 04 20:59:06 volumio volumio[21958]: info: Loading plugin "outputs"... Mar 04 20:59:06 volumio volumio[21958]: info: Loading plugin "albumart"... Mar 04 20:59:06 volumio volumio[21958]: info: Plugin example_plugin is not enabled Mar 04 20:59:06 volumio volumio[21958]: info: Loading plugin "inputs"... Mar 04 20:59:06 volumio volumio[21958]: info: Loading plugin "updater_comm"... Mar 04 20:59:07 volumio volumio[21958]: info: Plugin mpdemulation is not enabled Mar 04 20:59:07 volumio volumio[21958]: info: Loading plugin "rest_api"... Mar 04 20:59:07 volumio volumio[21958]: info: Loading plugin "websocket"... Mar 04 20:59:07 volumio volumio[21958]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:59:07 volumio volumio[21958]: info: Loading plugin "RoonBridge"... Mar 04 20:59:07 volumio volumio[21958]: info: Applying required configuration parameters for plugin RoonBridge Mar 04 20:59:07 volumio volumio[21958]: info: Loading i18n strings for locale en Mar 04 20:59:07 volumio volumio[21958]: Updating browse sources language Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:07 volumio volumio[22082]: Forking 3 albumart workers Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::initPlayerControls Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: Express server listening on port 3000 Mar 04 20:59:07 volumio volumio[21958]: [Metrics] WebUI: 8s 744.04ms Mar 04 20:59:07 volumio volumio[21958]: info: CoreStateMachine::resetVolumioState Mar 04 20:59:07 volumio volumio[21958]: info: CoreStateMachine::getcurrentVolume Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:59:07 volumio volumio[21958]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:59:07 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:07 volumio volumio[21958]: info: Reloading queue from file Mar 04 20:59:08 volumio volumio[21958]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::pushState Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::updateTrackBlock Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrackBlock Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::setRepeat null single undefined Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::pushState Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::setRandom null Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::pushState Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:08 volumio volumio[21958]: info: Setting Device type: Raspberry PI Mar 04 20:59:08 volumio volumio[21958]: info: Completed loading Core Plugins Mar 04 20:59:08 volumio volumio[21958]: info: Preparing to generate the ALSA configuration file Mar 04 20:59:08 volumio volumio[21958]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:59:08 volumio volumio[21958]: info: Discovery: Found device Volumio Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:08 volumio volumio[21958]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:59:08 volumio volumio[21958]: info: Discovery: Found device Volumio Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:08 volumio volumio[21958]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:59:08 volumio volumio[21958]: info: CoreStateMachine::pushState Mar 04 20:59:08 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:08 volumio volumio[21958]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:59:08 volumio volumio[21958]: info: Output device has changed, restarting MPD Mar 04 20:59:08 volumio volumio[21958]: info: Output device has changed, restarting Shairport Sync Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:08 volumio sudo[22136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:59:08 volumio sudo[22136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:08 volumio sudo[22136]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:08 volumio sudo[22138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:59:08 volumio volumio[21958]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:59:08 volumio sudo[22138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:08 volumio volumio[21958]: info: ___________ START PLUGINS ___________ Mar 04 20:59:08 volumio volumio[21958]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:59:08 volumio volumio[21958]: info: Creating MPD Configuration file Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:08 volumio volumio[21958]: info: [1772632748549] CoreMusicLibrary::Adding element Media Servers Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:59:08 volumio volumio[21958]: info: UPNP Browser: Client initialized successfully Mar 04 20:59:08 volumio sudo[22147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:59:08 volumio sudo[22148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:59:08 volumio sudo[22148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:08 volumio sudo[22147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:08 volumio sudo[22147]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:08 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:59:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:59:08 volumio systemd[1]: mpd.service: Consumed 4.358s CPU time. Mar 04 20:59:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:59:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:59:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:59:08 volumio volumio[21958]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:59:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:59:08 volumio volumio[21958]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:08 volumio volumio[21958]: info: [1772632748740] CoreMusicLibrary::Adding element Last_100 Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:08 volumio volumio[21958]: info: [1772632748747] CoreMusicLibrary::Adding element Webradio Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:59:08 volumio volumio[21958]: info: Initializing BBC Radios Mar 04 20:59:08 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:59:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:59:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:59:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:59:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:59:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:59:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:08 volumio volumio[21958]: info: Creating Spotify config file Mar 04 20:59:08 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:09 volumio sudo[22170]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:59:09 volumio sudo[22170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:59:09 volumio sudo[22170]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:09 volumio volumio[22094]: Starting albumart workers Mar 04 20:59:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 20:59:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:09 volumio volumio[22093]: Starting albumart workers Mar 04 20:59:09 volumio go-librespot[22178]: go-librespot daemon starting... Mar 04 20:59:09 volumio go-librespot[22179]: time="2026-03-04T20:59:09+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:09 volumio volumio[22092]: Starting albumart workers Mar 04 20:59:09 volumio volumio[21958]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:09 volumio volumio[21958]: info: [1772632749568] CoreMusicLibrary::Adding element YouTube Music Mar 04 20:59:09 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:09 volumio volumio[21958]: Cannot find translation for source YouTube Music Mar 04 20:59:09 volumio volumio[21958]: info: Volumio Calling Home Mar 04 20:59:09 volumio sudo[22188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Mar 04 20:59:09 volumio sudo[22188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:09 volumio sudo[22188]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:09 volumio go-librespot[22179]: time="2026-03-04T20:59:09+07:00" level=info msg="zeroconf server listening on port 44929" Mar 04 20:59:10 volumio volumio[21958]: info: MPD Permissions set Mar 04 20:59:10 volumio volumio[21958]: info: MPD Permissions set Mar 04 20:59:10 volumio volumio[21958]: info: Spotify config file written Mar 04 20:59:10 volumio sudo[22194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:59:10 volumio sudo[22194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:10 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 20:59:10 volumio volumio[21958]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:59:10 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 20:59:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio go-librespot[22202]: go-librespot daemon starting... Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio sudo[22194]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=debug msg="app state loaded" Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:10 volumio volumio[21958]: info: No need to fix Spotify hosts Mar 04 20:59:10 volumio volumio[21958]: info: Volumio called home Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 04 20:59:10 volumio go-librespot[22214]: time="2026-03-04T20:59:10+07:00" level=info msg="zeroconf server listening on port 42571" Mar 04 20:59:11 volumio volumio[21958]: info: Starting Shairport Sync Mar 04 20:59:11 volumio volumio[21958]: info: Starting Shairport Sync Mar 04 20:59:11 volumio volumio[21958]: info: Starting Shairport Sync Mar 04 20:59:11 volumio sudo[22233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:59:11 volumio sudo[22233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:11 volumio sudo[22235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:59:11 volumio sudo[22235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:11 volumio sudo[22237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:59:11 volumio sudo[22237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:59:11 volumio go-librespot[22214]: time="2026-03-04T20:59:11+07:00" level=debug msg="obtained new client token: AADyrpJ25R4P1O1hp68Gw0LXGhqNkSF9JqPLiNM+1sWsEi15x9z1QBzu6XZlHfY+jDQrK1lF1u2HrS/7UjdQyxLCTLSZdNKY4z+KxiwqocmNXQwGaOe9WDdDMDW+KzGKaMF9UaWstDL68SaDKPn3bNxHiHkkbFAzerA+rHw411C17i0BDEm5cmVuptoLAugb3JyY6R3wAU95uqs/AwJo3VJnohtdR3Lr+Ip3tbpqeGVyph7fDNhbmQ0=" Mar 04 20:59:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:59:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:11 volumio systemd[1]: shairport-sync.service: Consumed 1.834s CPU time. Mar 04 20:59:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:11 volumio sudo[22233]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:11 volumio volumio[21958]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:59:11 volumio volumio[21958]: SPOTIFY: BQCWlHpOJvNcj7jS4wUN_1NhNqhsVpOANsz_-pXmky3VewXQbqem4bUcfmJtJHiD6GJ2Igo-nEZwXIjBDwWiIdCV-uGDgvjhTQSU6oYjGDwdCbd8ZhMTD4_4_hSCt20k7FTNYQHzYbGnIwbx5ZUaqbuuXiNQtRpAaEvd12cWCqFIuM7zYLHgXMWC61hu5sJLisK5KjB_dWrq_BfoSa15GMHyl_AktwGZQ4lD3nbaYcZIRfEKOXgzkbh4VKvnvbgx8JDuwB1O4wKMdVqwD5_w3-rNCH7egtNi8P2XROMhsSTeYkYnIfRMELKk Mar 04 20:59:11 volumio volumio[21958]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:59:11 volumio go-librespot[22214]: time="2026-03-04T20:59:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:11 volumio volumio[21958]: info: New Spotify access token = BQCWlHpOJvNcj7jS4wUN_1NhNqhsVpOANsz_-pXmky3VewXQbqem4bUcfmJtJHiD6GJ2Igo-nEZwXIjBDwWiIdCV-uGDgvjhTQSU6oYjGDwdCbd8ZhMTD4_4_hSCt20k7FTNYQHzYbGnIwbx5ZUaqbuuXiNQtRpAaEvd12cWCqFIuM7zYLHgXMWC61hu5sJLisK5KjB_dWrq_BfoSa15GMHyl_AktwGZQ4lD3nbaYcZIRfEKOXgzkbh4VKvnvbgx8JDuwB1O4wKMdVqwD5_w3-rNCH7egtNi8P2XROMhsSTeYkYnIfRMELKk Mar 04 20:59:11 volumio volumio[21958]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 04 20:59:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:59:11 volumio sudo[22235]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:59:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:11 volumio sudo[22237]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:11 volumio go-librespot[22214]: time="2026-03-04T20:59:11+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:11 volumio go-librespot[22214]: time="2026-03-04T20:59:11+07:00" level=debug msg="completed challenge" Mar 04 20:59:11 volumio volumio[21958]: info: Shairport-Sync Started Mar 04 20:59:11 volumio volumio[21958]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:59:11 volumio volumio[21958]: info: Shairport-Sync Started Mar 04 20:59:11 volumio volumio[21958]: info: Shairport-Sync Started Mar 04 20:59:11 volumio volumio[21958]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:11 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:11 volumio go-librespot[22214]: time="2026-03-04T20:59: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 " Mar 04 20:59:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:11 volumio sudo[22274]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:59:11 volumio sudo[22274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:11 volumio sudo[22274]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:11 volumio sudo[22275]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:59:11 volumio sudo[22275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:11 volumio sudo[22275]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:11 volumio volumio[21958]: 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"} Mar 04 20:59:11 volumio volumio[21958]: info: Spotify Successfully logged in Mar 04 20:59:11 volumio volumio[21958]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:11 volumio volumio[21958]: info: [1772632751810] CoreMusicLibrary::Adding element Spotify Mar 04 20:59:11 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:11 volumio volumio[21958]: Cannot find translation for source YouTube Music Mar 04 20:59:11 volumio volumio[21958]: Cannot find translation for source Spotify Mar 04 20:59:11 volumio sudo[22279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:59:11 volumio sudo[22279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:12 volumio sudo[22279]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:12 volumio volumio[21958]: info: Upmpdcli Daemon Started Mar 04 20:59:12 volumio volumio[21958]: info: [yt-cast-receiver] DIAL server listening on port 8098 Mar 04 20:59:12 volumio volumio[21958]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:59:12 volumio volumio[21958]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:59:12 volumio volumio[21958]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:12 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:12 volumio volumio[21958]: info: CoreStateMachine::pushState Mar 04 20:59:12 volumio volumio[21958]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:12 volumio volumio[21958]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:13 volumio mpd[22177]: 2026-03-04T20:59:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:59:13 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:59:13 volumio sudo[22148]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:13 volumio sudo[22138]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:13 volumio volumio[21958]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:59:13 volumio volumio[21958]: assert.ok(self.idling) Mar 04 20:59:13 volumio volumio[21958]: error: The expression evaluated to a falsy value: Mar 04 20:59:13 volumio volumio[21958]: assert.ok(self.idling) Mar 04 20:59:13 volumio volumio[21958]: error: updateQueue error: null Mar 04 20:59:13 volumio volumio[21958]: info: MPD running with PID22177 Mar 04 20:59:13 volumio volumio[21958]: ,establishing connection Mar 04 20:59:13 volumio volumio[21958]: info: Completed starting Core Plugins Mar 04 20:59:13 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:59:13 volumio volumio[21958]: info: ----- MyVolumio plugins startup ---- Mar 04 20:59:13 volumio volumio[21958]: info: ------------------------------------------- Mar 04 20:59:13 volumio volumio[21958]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:59:13 volumio volumio[21958]: error: updateQueue error: null Mar 04 20:59:14 volumio volumio[21958]: info: go-librespot daemon successfully initialized Mar 04 20:59:14 volumio volumio-remote-updater[675]: [2026-03-04 20:59:14] [connect] Successful connection Mar 04 20:59:14 volumio volumio-remote-updater[675]: [2026-03-04 20:59:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772632754 101 Mar 04 20:59:14 volumio volumio[21958]: 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: 2 Mar 04 20:59:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 20:59:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:14 volumio go-librespot[22288]: go-librespot daemon starting... Mar 04 20:59:14 volumio go-librespot[22289]: time="2026-03-04T20:59:14+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:14 volumio go-librespot[22289]: time="2026-03-04T20:59:14+07:00" level=debug msg="app state loaded" Mar 04 20:59:14 volumio go-librespot[22289]: time="2026-03-04T20:59:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+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]" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+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]" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+07:00" level=info msg="zeroconf server listening on port 44381" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+07:00" level=debug msg="obtained new client token: AACeh/KLH02G24bHH/2Ou3zNT4If5wqOh0JZ5Lxlw6xZY8/5d8IKy7MANr+JUHzYo4QYhyv5T1hhECw/gWLiuXVrkns4vsBPEQ21oZ7kzf2lZjvjoH6lVnzv+hLLZSTI4Eql+xU+mj9kJ4/8TfD64LrrQ/+aGkVrWN/1xCU969IWsMoa8VOxteI0z3w8QLPkuvftu0581nydLWHkc6sAmdK1HVP8sWUlqnjVyv68sWMBUoyTaPwoU5PLpQ==" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+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" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Mar 04 20:59:15 volumio go-librespot[22289]: time="2026-03-04T20:59:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 04 20:59:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:17 volumio volumio[21958]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:17 volumio volumio[21958]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:59:18 volumio volumio[21958]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:59:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 20:59:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:18 volumio go-librespot[22339]: go-librespot daemon starting... Mar 04 20:59:18 volumio go-librespot[22340]: time="2026-03-04T20:59:18+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:18 volumio go-librespot[22340]: time="2026-03-04T20:59:18+07:00" level=debug msg="app state loaded" Mar 04 20:59:18 volumio go-librespot[22340]: time="2026-03-04T20:59:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+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]" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+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]" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+07:00" level=info msg="zeroconf server listening on port 44755" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+07:00" level=debug msg="obtained new client token: AAA3WpHLAR/LN/UF+n2xJSbHKiCifeM7gYT1e2jJLFV1j0LesQP0YvUpkosumvn4fijeUVBggtb6Gb+LKOWqSDPyMjMUJA9t+WvMkWqbBPhmCoYO3t6o7m/Xk22QVg863QvF2bhLPgjBaKfwZEnX5lqtrT1GABLx1zzibHZKORn6tv6LuIsrsAGy+3EgMzAv03Ky7SCBjua3SuwqDae5mqaYiThlw9gmAC94SusvrkwkdFpftU2A42E=" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59:19+07:00" level=debug msg="completed challenge" Mar 04 20:59:19 volumio go-librespot[22340]: time="2026-03-04T20:59: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 " Mar 04 20:59:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:20 volumio volumio[21958]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:20 volumio volumio[21958]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:59:22 volumio volumio[21958]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:59:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 20:59:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:22 volumio go-librespot[22363]: go-librespot daemon starting... Mar 04 20:59:22 volumio go-librespot[22364]: time="2026-03-04T20:59:22+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:22 volumio go-librespot[22364]: time="2026-03-04T20:59:22+07:00" level=debug msg="app state loaded" Mar 04 20:59:22 volumio go-librespot[22364]: time="2026-03-04T20:59:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:23 volumio volumio[21958]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:59:23 volumio volumio[21958]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:59:23 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:23 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:23 volumio volumio[21958]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:59:23 volumio volumio[21958]: info: MyVolumio login type: Token Mar 04 20:59:23 volumio volumio[21958]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:59:23 volumio volumio[21958]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=info msg="zeroconf server listening on port 39975" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="obtained new client token: AAA6iXoM9X3MlpfF9DqWlRw/gXSCaYXvCNYjL38EurY5iLKlwgCOMMPx+w233CIRkRV6gSZc2bekDZCcimDMdbL8PcdWt4WXjW/TYgAdB82575VCJH01/uzqdF9rRon3tazW/tehOVQ8nM4MpdC6rI2ariiAAUeKqfaUeVNBuYESD+ANv4Vv/4r1GOdjp6bHjLzXBlYcXnfc14Fq2jqOV8l/tqx2dCjtAzLDfSF9Iu8sDUTUHbxuCHe8KQ==" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59:23+07:00" level=debug msg="completed challenge" Mar 04 20:59:23 volumio go-librespot[22364]: time="2026-03-04T20:59: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 " Mar 04 20:59:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:24 volumio volumio[21958]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:59:24 volumio volumio[21958]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:59:24 volumio volumio[21958]: info: Streaming services startup Mar 04 20:59:24 volumio volumio[21958]: info: Starting Streaming Daemon Mar 04 20:59:24 volumio sudo[22373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:59:24 volumio sudo[22373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:24 volumio volumio[21958]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:59:24 volumio sudo[22373]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:24 volumio volumio[21958]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:24 volumio volumio[21958]: error: Cannot start Volumio Streaming Daemon Mar 04 20:59:24 volumio volumio[21958]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:59:24 volumio volumio[21958]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:59:24 volumio volumio[21958]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:59:24 volumio volumio[21958]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 20:59:25 volumio volumio[21958]: info: MyVolumio token set successfully Mar 04 20:59:25 volumio volumio[21958]: info: MYVOLUMIO: Adding device Mar 04 20:59:25 volumio volumio[21958]: info: MYVOLUMIO: Evaluating Server Mar 04 20:59:26 volumio volumio[21958]: info: MyVolumio status changed Mar 04 20:59:26 volumio volumio[21958]: info: Streaming services startup Mar 04 20:59:26 volumio volumio[21958]: info: Starting Streaming Daemon Mar 04 20:59:26 volumio volumio[21958]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 20:59:26 volumio volumio[21958]: info: Removing audio output: Mar 04 20:59:26 volumio volumio[21958]: info: Stoppping Tunnel 1 Mar 04 20:59:26 volumio sudo[22400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:59:26 volumio sudo[22400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:26 volumio sudo[22402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 04 20:59:26 volumio sudo[22402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:26 volumio sudo[22400]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:26 volumio volumio[21958]: error: Cannot start Volumio Streaming Daemon Mar 04 20:59:26 volumio volumio[21958]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:59:26 volumio volumio[21958]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 04 20:59:26 volumio sudo[22402]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:26 volumio volumio[21958]: info: Remote SSH Stopped Mar 04 20:59:26 volumio volumio[21958]: info: Setting Geolocation for MyVolumio to as1 Mar 04 20:59:26 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:26 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:26 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:26 volumio volumio[21958]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 04 20:59:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 20:59:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:26 volumio go-librespot[22405]: go-librespot daemon starting... Mar 04 20:59:26 volumio go-librespot[22406]: time="2026-03-04T20:59:26+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:26 volumio go-librespot[22406]: time="2026-03-04T20:59:26+07:00" level=debug msg="app state loaded" Mar 04 20:59:26 volumio go-librespot[22406]: time="2026-03-04T20:59:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+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]" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+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]" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+07:00" level=info msg="zeroconf server listening on port 32849" Mar 04 20:59:27 volumio volumio[21958]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+07:00" level=debug msg="new websocket client" Mar 04 20:59:27 volumio volumio[21958]: info: Connection to go-librespot Websocket established Mar 04 20:59:27 volumio volumio[21958]: info: Updating MyVolumio device info Mar 04 20:59:27 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:27 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:27 volumio volumio[21958]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+07:00" level=debug msg="obtained new client token: AADxtg6DMgco/hJPjsBGCb/FNBlm/9wGhlNzsoxDoERMBu1mTDV7uDvL/5EuHXJyXMBGwDO3elYKm5LnLIDLJNzayMTMxDTYqTnvTovSN3AzV4cAGuGNSy1e9f9BPNx+hMCQgGCs3dVtQqgZZ98NvhYRPNPJMpYdiYCvpsd8PoZbfgWtUNFvZKvnXIJYf2x70ofo2B12kEHykvdWb6UwcxD2mwneetJr+dmaJgnIIrDfZmZZEf3cyvaCoQ==" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+07:00" level=debug msg="completed challenge" Mar 04 20:59:27 volumio go-librespot[22406]: time="2026-03-04T20:59:27+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 " Mar 04 20:59:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:27 volumio volumio[21958]: info: Connection to go-librespot Websocket closed Mar 04 20:59:27 volumio volumio[21958]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 04 20:59:30 volumio volumio[21958]: info: Getting Spotify volume Mar 04 20:59:30 volumio volumio[21958]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:59:30 volumio volumio[21958]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:59:30 volumio volumio[21958]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 20:59:30 volumio volumio[21958]: errno: -111, Mar 04 20:59:30 volumio volumio[21958]: code: 'ECONNREFUSED', Mar 04 20:59:30 volumio volumio[21958]: syscall: 'connect', Mar 04 20:59:30 volumio volumio[21958]: address: '127.0.0.1', Mar 04 20:59:30 volumio volumio[21958]: port: 9879, Mar 04 20:59:30 volumio volumio[21958]: response: undefined Mar 04 20:59:30 volumio volumio[21958]: } Mar 04 20:59:30 volumio volumio[21958]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:59:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 20:59:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:30 volumio go-librespot[22425]: go-librespot daemon starting... Mar 04 20:59:30 volumio go-librespot[22426]: time="2026-03-04T20:59:30+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:30 volumio go-librespot[22426]: time="2026-03-04T20:59:30+07:00" level=debug msg="app state loaded" Mar 04 20:59:30 volumio go-librespot[22426]: time="2026-03-04T20:59:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:30 volumio sudo[22435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:58' Mar 04 20:59:30 volumio sudo[22435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:31 volumio sudo[22435]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+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]" Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+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]" Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+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]" Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+07:00" level=info msg="zeroconf server listening on port 40935" Mar 04 20:59:31 volumio volumio-remote-updater[675]: [2026-03-04 20:59:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 20:59:31 volumio volumio-remote-updater[675]: [2026-03-04 20:59:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 20:59:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 20:59:31 volumio systemd[1]: volumio.service: Consumed 31.845s CPU time. Mar 04 20:59:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:59:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+07:00" level=debug msg="obtained new client token: AADwPH4UEywquxnZNgCcvSjeFhBhVvaG1g1CAuW3u/R37613HN554VKscKSDQ6/YI/u/D7+dDX8RYeWby1V4vM7kuj1FF6S5yjEnyKScEeE9pIJRykGwvwzInMnfu1cJ0M2oGCLOBPCxdFHtJoOwu2CRqkEF/mG5q0PDPlch51WgEpYtqs3WkLZ8io/8VAH9lOenYG0gmVM9QG0z9XfMERKlcG9hBmMNyzHvP4mJ3r5YkZwuroInqJMo8A==" Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 36. Mar 04 20:59:31 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+07:00" level=debug msg="completed challenge" Mar 04 20:59:31 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 20:59:31 volumio systemd[1]: volumio.service: Consumed 31.845s CPU time. Mar 04 20:59:31 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 20:59:31 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:59:31 volumio go-librespot[22426]: time="2026-03-04T20:59:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:59:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:33 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:33 volumio volumio[22447]: info: ----- Volumio3 ---- Mar 04 20:59:33 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:33 volumio volumio[22447]: info: ----- System startup ---- Mar 04 20:59:33 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:34 volumio volumio[22447]: info: MYVOLUMIO Environment detected Mar 04 20:59:34 volumio volumio[22447]: info: Plugin folders cleanup Mar 04 20:59:34 volumio volumio[22447]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category audio_interface Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category miscellanea Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category music_service Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category plugins.json Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category system_controller Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category user_interface Mar 04 20:59:34 volumio volumio[22447]: info: Scanning into folder /data/plugins/ Mar 04 20:59:34 volumio volumio[22447]: info: Scanning category music_service Mar 04 20:59:34 volumio volumio[22447]: info: Plugin folders cleanup completed Mar 04 20:59:34 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:34 volumio volumio[22447]: info: ----- Core plugins startup ---- Mar 04 20:59:34 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:34 volumio volumio[22447]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:59:34 volumio volumio[22447]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:59:34 volumio volumio[22447]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:59:34 volumio volumio[22447]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:59:34 volumio volumio[22447]: info: Loading plugins from folder /data/plugins/ Mar 04 20:59:34 volumio volumio[22447]: info: Loading plugin "system"... Mar 04 20:59:34 volumio volumio[22447]: info: Loading plugin "appearance"... Mar 04 20:59:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 20:59:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:34 volumio go-librespot[22519]: go-librespot daemon starting... Mar 04 20:59:34 volumio go-librespot[22520]: time="2026-03-04T20:59:34+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:34 volumio go-librespot[22520]: time="2026-03-04T20:59:34+07:00" level=debug msg="app state loaded" Mar 04 20:59:34 volumio go-librespot[22520]: time="2026-03-04T20:59:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+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]" Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+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]" Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+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]" Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+07:00" level=info msg="zeroconf server listening on port 46203" Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "network"... Mar 04 20:59:35 volumio volumio[22447]: info: Refreshing Cached IP Addresses Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+07:00" level=debug msg="obtained new client token: AACnOS3xq5XmFtdoGVBZqHhNiEywStbMQfasQhyrG1kxhxqNb3ELaef7BVgYzdGSKtoQ/54Q9KPfeH3kZBNbavXvJRy9drloTTvIcEaZl3lo8Nx7xF7VvEMHGz7n0ypfO4zeRArF/DmEEK7ssn8WjwU9xPzReWGCqv/55oZmbnygOIiuVX+FbQGdZHSEDzALNGRwfV5lNFqwAYZE8qjpgO+1PTLDkxSvtyaT8dv0CeLEhm9c4X/Y6fRR1A==" Mar 04 20:59:35 volumio sudo[22528]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:59:35 volumio sudo[22528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:35 volumio sudo[22528]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:35 volumio sudo[22530]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "services"... Mar 04 20:59:35 volumio sudo[22530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "alsa_controller"... Mar 04 20:59:35 volumio sudo[22530]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:35 volumio sudo[22539]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:59:35 volumio sudo[22539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:35 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "wizard"... Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "networkfs"... Mar 04 20:59:35 volumio volumio[22447]: info: Starting Udev Watcher for removable devices Mar 04 20:59:35 volumio volumio[22447]: info: Ignoring mount for partition: boot Mar 04 20:59:35 volumio volumio[22447]: info: Ignoring mount for partition: volumio Mar 04 20:59:35 volumio volumio[22447]: info: Ignoring mount for partition: volumio_data Mar 04 20:59:35 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "upnp"... Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+07:00" level=debug msg="completed challenge" Mar 04 20:59:35 volumio volumio[22447]: info: [1772632775575] Starting Upmpd Daemon Mar 04 20:59:35 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "my_music"... Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "mpd"... Mar 04 20:59:35 volumio go-librespot[22520]: time="2026-03-04T20:59:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:59:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:35 volumio volumio[22447]: info: Loading plugin "upnp_browser"... Mar 04 20:59:36 volumio volumio-remote-updater[675]: [2026-03-04 20:59:36] [connect] Successful connection Mar 04 20:59:37 volumio volumio[22447]: info: Starting UPNP Browser Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "alarm-clock"... Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "airplay_emulation"... Mar 04 20:59:37 volumio volumio[22447]: info: Starting Shairport Sync Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "last_100"... Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "webradio"... Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "i2s_dacs"... Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "volumiodiscovery"... Mar 04 20:59:37 volumio volumio[22447]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:37 volumio volumio[22447]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:37 volumio volumio[22447]: *** WARNING *** For more information see Mar 04 20:59:37 volumio volumio[22447]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:37 volumio volumio[22447]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:37 volumio volumio[22447]: *** WARNING *** For more information see Mar 04 20:59:37 volumio node[22447]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:37 volumio node[22447]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:37 volumio node[22447]: *** WARNING *** For more information see Mar 04 20:59:37 volumio node[22447]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:59:37 volumio node[22447]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:59:37 volumio node[22447]: *** WARNING *** For more information see Mar 04 20:59:37 volumio volumio[22447]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:59:37 volumio volumio[22447]: info: Discovery: Started advertising with name: Volumio Mar 04 20:59:37 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:59:37 volumio volumio[22447]: info: Loading plugin "spop"... Mar 04 20:59:37 volumio sudo[22539]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 20:59:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:38 volumio go-librespot[22564]: go-librespot daemon starting... Mar 04 20:59:38 volumio go-librespot[22565]: time="2026-03-04T20:59:38+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:38 volumio go-librespot[22565]: time="2026-03-04T20:59:38+07:00" level=debug msg="app state loaded" Mar 04 20:59:38 volumio go-librespot[22565]: time="2026-03-04T20:59:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:38 volumio volumio[22447]: info: Loading plugin "ytcr"... Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+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]" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+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]" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+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]" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+07:00" level=info msg="zeroconf server listening on port 33929" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+07:00" level=debug msg="obtained new client token: AAA1u8CogBpvjvIYmf6KyJkSa3+bPWMEIJFLFgVYadt8G+ecCvfkqIW0YI8ruLR+WFOYU7LbnELnPvmCx0rNYA1qKaUig789MMZJUCt08zwjJcgQl+xIdFq8Y4HXavGHj/GVSQsczNZyOlLA7Kp7nNV0VdvFX6zsYE8DS2Onh/JxFRMgM/YZrJB/UnWiZ+/F7WE57YlYPSIAJcqSmYQSZPlXcnx9uHiUdStkDpt8Mart1qJvX0W0xQhnYw==" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+07:00" level=debug msg="completed challenge" Mar 04 20:59:39 volumio go-librespot[22565]: time="2026-03-04T20:59:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:59:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:40 volumio volumio[22447]: info: Loading plugin "ytmusic"... Mar 04 20:59:40 volumio volumio[22447]: info: Loading plugin "outputs"... Mar 04 20:59:40 volumio volumio[22447]: info: Loading plugin "albumart"... Mar 04 20:59:40 volumio volumio[22447]: info: Plugin example_plugin is not enabled Mar 04 20:59:40 volumio volumio[22447]: info: Loading plugin "inputs"... Mar 04 20:59:40 volumio volumio[22447]: info: Loading plugin "updater_comm"... Mar 04 20:59:41 volumio volumio[22447]: info: Plugin mpdemulation is not enabled Mar 04 20:59:41 volumio volumio[22447]: info: Loading plugin "rest_api"... Mar 04 20:59:41 volumio volumio[22447]: info: Loading plugin "websocket"... Mar 04 20:59:41 volumio volumio[22447]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:59:41 volumio volumio[22447]: info: Loading plugin "RoonBridge"... Mar 04 20:59:41 volumio volumio[22447]: info: Applying required configuration parameters for plugin RoonBridge Mar 04 20:59:41 volumio volumio[22447]: info: Loading i18n strings for locale en Mar 04 20:59:41 volumio volumio[22447]: Updating browse sources language Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::initPlayerControls Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:41 volumio volumio[22572]: Forking 3 albumart workers Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: Express server listening on port 3000 Mar 04 20:59:41 volumio volumio[22447]: [Metrics] WebUI: 8s 695.33ms Mar 04 20:59:41 volumio volumio[22447]: info: CoreStateMachine::resetVolumioState Mar 04 20:59:41 volumio volumio[22447]: info: CoreStateMachine::getcurrentVolume Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:59:41 volumio volumio[22447]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:41 volumio volumio[22447]: info: Reloading queue from file Mar 04 20:59:41 volumio volumio[22447]: info: CoreStateMachine::setRepeat null single undefined Mar 04 20:59:41 volumio volumio[22447]: info: CoreStateMachine::pushState Mar 04 20:59:41 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:41 volumio volumio[22447]: info: CoreStateMachine::setRandom null Mar 04 20:59:41 volumio volumio[22447]: info: CoreStateMachine::pushState Mar 04 20:59:41 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:41 volumio volumio[22447]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:41 volumio volumio[22447]: info: Setting Device type: Raspberry PI Mar 04 20:59:42 volumio volumio[22447]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:59:42 volumio volumio[22447]: info: CoreStateMachine::pushState Mar 04 20:59:42 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:42 volumio volumio[22447]: info: CoreStateMachine::updateTrackBlock Mar 04 20:59:42 volumio volumio[22447]: info: CorePlayQueue::getTrackBlock Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:59:42 volumio volumio[22447]: info: Completed loading Core Plugins Mar 04 20:59:42 volumio volumio[22447]: info: Preparing to generate the ALSA configuration file Mar 04 20:59:42 volumio volumio[22447]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:59:42 volumio volumio[22447]: info: Discovery: Found device Volumio Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:42 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:42 volumio volumio[22447]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:59:42 volumio volumio[22447]: info: CoreStateMachine::pushState Mar 04 20:59:42 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:42 volumio volumio[22447]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Mar 04 20:59:42 volumio volumio[22447]: info: Discovery: Found device Volumio Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:42 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:42 volumio volumio[22447]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:59:42 volumio volumio[22447]: info: Output device has changed, restarting MPD Mar 04 20:59:42 volumio volumio[22447]: info: Output device has changed, restarting Shairport Sync Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:42 volumio sudo[22626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:59:42 volumio sudo[22626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:42 volumio sudo[22626]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:42 volumio sudo[22628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:59:42 volumio sudo[22628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:42 volumio volumio[22447]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:59:42 volumio volumio[22447]: info: ___________ START PLUGINS ___________ Mar 04 20:59:42 volumio volumio[22447]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:59:42 volumio volumio[22447]: info: Creating MPD Configuration file Mar 04 20:59:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:59:42 volumio sudo[22636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:59:42 volumio sudo[22636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:42 volumio volumio[22447]: info: [1772632782368] CoreMusicLibrary::Adding element Media Servers Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:42 volumio sudo[22636]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:42 volumio volumio[22447]: info: UPNP Browser: Client initialized successfully Mar 04 20:59:42 volumio sudo[22638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:59:42 volumio sudo[22638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:42 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:59:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:59:42 volumio systemd[1]: mpd.service: Consumed 4.234s CPU time. Mar 04 20:59:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:59:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:59:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:42 volumio volumio[22447]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:59:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:59:42 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:59:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:59:42 volumio volumio[22447]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:59:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:42 volumio volumio[22447]: info: [1772632782579] CoreMusicLibrary::Adding element Last_100 Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:59:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:42 volumio volumio[22447]: info: [1772632782588] CoreMusicLibrary::Adding element Webradio Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:59:42 volumio volumio[22447]: info: Initializing BBC Radios Mar 04 20:59:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:59:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:59:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 20:59:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:42 volumio go-librespot[22666]: go-librespot daemon starting... Mar 04 20:59:42 volumio volumio[22447]: info: Creating Spotify config file Mar 04 20:59:42 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:42 volumio go-librespot[22667]: time="2026-03-04T20:59:42+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:42 volumio sudo[22660]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:59:42 volumio sudo[22660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:59:42 volumio sudo[22660]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:43 volumio volumio[22582]: Starting albumart workers Mar 04 20:59:43 volumio volumio[22586]: Starting albumart workers Mar 04 20:59:43 volumio go-librespot[22667]: time="2026-03-04T20:59:43+07:00" level=info msg="zeroconf server listening on port 46829" Mar 04 20:59:43 volumio volumio[22447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:43 volumio volumio[22447]: info: [1772632783818] CoreMusicLibrary::Adding element YouTube Music Mar 04 20:59:43 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:43 volumio volumio[22447]: Cannot find translation for source YouTube Music Mar 04 20:59:43 volumio volumio[22447]: info: Volumio Calling Home Mar 04 20:59:43 volumio volumio[22587]: Starting albumart workers Mar 04 20:59:43 volumio sudo[22677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Mar 04 20:59:43 volumio sudo[22677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:44 volumio sudo[22677]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:44 volumio volumio[22447]: info: MPD Permissions set Mar 04 20:59:44 volumio volumio[22447]: info: MPD Permissions set Mar 04 20:59:44 volumio volumio[22447]: info: Spotify config file written Mar 04 20:59:44 volumio sudo[22683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:59:44 volumio sudo[22683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:44 volumio volumio[22447]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 20:59:44 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 20:59:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:59:44 volumio volumio[22447]: info: No need to fix Spotify hosts Mar 04 20:59:44 volumio go-librespot[22702]: go-librespot daemon starting... Mar 04 20:59:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:44 volumio sudo[22683]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:44 volumio go-librespot[22708]: time="2026-03-04T20:59:44+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:44 volumio go-librespot[22708]: time="2026-03-04T20:59:44+07:00" level=debug msg="app state loaded" Mar 04 20:59:44 volumio go-librespot[22708]: time="2026-03-04T20:59:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:44 volumio volumio[22447]: info: Volumio called home Mar 04 20:59:44 volumio volumio[22447]: info: Starting Shairport Sync Mar 04 20:59:44 volumio volumio[22447]: info: Starting Shairport Sync Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59: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-gew1.spotify.com:80]" Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59:45+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]" Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59:45+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]" Mar 04 20:59:45 volumio volumio[22447]: info: Starting Shairport Sync Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59:45+07:00" level=info msg="zeroconf server listening on port 41129" Mar 04 20:59:45 volumio sudo[22716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:59:45 volumio sudo[22716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:45 volumio sudo[22720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:59:45 volumio sudo[22720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:45 volumio sudo[22719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:59:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:59:45 volumio sudo[22719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:59:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:45 volumio systemd[1]: shairport-sync.service: Consumed 1.833s CPU time. Mar 04 20:59:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:45 volumio sudo[22716]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59:45+07:00" level=debug msg="obtained new client token: AACiKRsuiC2Qd0IbSTxBSPYAkKWuRSgw2RlHxBKyYazUrM9U9FDnmtKOxXLs9vgf2/yhwW8HW988OezFGcCXNOrWuI+cnrwRMim229FNZyFbLZLGKKLN8k2x0+qAR04mwzsb7XKDYdye821icjZfiGEIXc1Un8U4etyIVnC0Dgav2l4gY92X3BsSWF1Ya1Yj9sR+Cv5/N6h0HrxeA1EuwIP3Kb01LnsNC3lCdgsgIpChz0338r5qEtU=" Mar 04 20:59:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:59:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:59:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:59:45 volumio sudo[22720]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:45 volumio sudo[22719]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:45 volumio volumio[22447]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:59:45 volumio volumio[22447]: SPOTIFY: BQBBmHpfp8LiQDmpjyXvThCleP-_54-4DZ4c4zTaFXBFZaR4VU1Xyb2fi-Ptxi6wvAh84tz96XNvsykWMZ4HTp7gyBE8E0K6r5w2YlsCXsR0LmfYepzSpqm3WYqxNbcb54fqxa0lumikx93iwnnwuu5g6CKsxv-0oPx2krCrNJ9bu9d9CmKVA0mG31KdrK1SNfAkr2LXm99aFPCQHsuOIM8oJPkVV_yCQbwE7g4BHkUJS45yFuLbUY5ryKDSFoljqaAhpQmnuzPbgbSINqz10q9oxFf1CrGHnd6OhTYOFWOjsVgriber75Is Mar 04 20:59:45 volumio volumio[22447]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 04 20:59:45 volumio volumio[22447]: info: New Spotify access token = BQBBmHpfp8LiQDmpjyXvThCleP-_54-4DZ4c4zTaFXBFZaR4VU1Xyb2fi-Ptxi6wvAh84tz96XNvsykWMZ4HTp7gyBE8E0K6r5w2YlsCXsR0LmfYepzSpqm3WYqxNbcb54fqxa0lumikx93iwnnwuu5g6CKsxv-0oPx2krCrNJ9bu9d9CmKVA0mG31KdrK1SNfAkr2LXm99aFPCQHsuOIM8oJPkVV_yCQbwE7g4BHkUJS45yFuLbUY5ryKDSFoljqaAhpQmnuzPbgbSINqz10q9oxFf1CrGHnd6OhTYOFWOjsVgriber75Is Mar 04 20:59:45 volumio volumio[22447]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 04 20:59:45 volumio go-librespot[22708]: time="2026-03-04T20:59:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:42204->104.199.241.202:4070: read: connection reset by peer" Mar 04 20:59:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:45 volumio volumio[22447]: info: Shairport-Sync Started Mar 04 20:59:45 volumio volumio[22447]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:59:45 volumio sudo[22763]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:59:45 volumio sudo[22763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:45 volumio sudo[22763]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:45 volumio sudo[22764]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:59:45 volumio sudo[22764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:45 volumio sudo[22764]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:45 volumio volumio[22447]: info: Shairport-Sync Started Mar 04 20:59:45 volumio volumio[22447]: info: Shairport-Sync Started Mar 04 20:59:45 volumio volumio[22447]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:45 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:45 volumio sudo[22768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:59:45 volumio sudo[22768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:45 volumio sudo[22768]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:45 volumio volumio[22447]: info: Upmpdcli Daemon Started Mar 04 20:59:46 volumio volumio[22447]: 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"} Mar 04 20:59:46 volumio volumio[22447]: info: Spotify Successfully logged in Mar 04 20:59:46 volumio volumio[22447]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:59:46 volumio volumio[22447]: info: [1772632786065] CoreMusicLibrary::Adding element Spotify Mar 04 20:59:46 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:59:46 volumio volumio[22447]: Cannot find translation for source YouTube Music Mar 04 20:59:46 volumio volumio[22447]: Cannot find translation for source Spotify Mar 04 20:59:46 volumio volumio[22447]: info: [yt-cast-receiver] DIAL server listening on port 8098 Mar 04 20:59:46 volumio volumio[22447]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:59:46 volumio volumio[22447]: info: VolumeController:: Volume=100 Mute =false Mar 04 20:59:46 volumio volumio[22447]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:46 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:46 volumio volumio[22447]: info: CoreStateMachine::pushState Mar 04 20:59:46 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:46 volumio volumio[22447]: info: CoreCommandRouter::volumioPushState Mar 04 20:59:47 volumio mpd[22674]: 2026-03-04T20:59:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:59:47 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:59:47 volumio sudo[22628]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:47 volumio sudo[22638]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:47 volumio volumio[22447]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:59:47 volumio volumio[22447]: assert.ok(self.idling) Mar 04 20:59:47 volumio volumio[22447]: error: The expression evaluated to a falsy value: Mar 04 20:59:47 volumio volumio[22447]: assert.ok(self.idling) Mar 04 20:59:47 volumio volumio[22447]: info: MPD running with PID22674 Mar 04 20:59:47 volumio volumio[22447]: ,establishing connection Mar 04 20:59:47 volumio volumio[22447]: error: updateQueue error: null Mar 04 20:59:47 volumio volumio[22447]: info: Completed starting Core Plugins Mar 04 20:59:47 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:47 volumio volumio[22447]: info: ----- MyVolumio plugins startup ---- Mar 04 20:59:47 volumio volumio[22447]: info: ------------------------------------------- Mar 04 20:59:47 volumio volumio[22447]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:59:47 volumio volumio[22447]: error: updateQueue error: null Mar 04 20:59:47 volumio volumio[22447]: info: go-librespot daemon successfully initialized Mar 04 20:59:48 volumio volumio-remote-updater[675]: [2026-03-04 20:59:48] [connect] Successful connection Mar 04 20:59:48 volumio volumio-remote-updater[675]: [2026-03-04 20:59:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772632788 101 Mar 04 20:59:48 volumio volumio[22447]: 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: 2 Mar 04 20:59:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 20:59:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:48 volumio go-librespot[22820]: go-librespot daemon starting... Mar 04 20:59:48 volumio go-librespot[22821]: time="2026-03-04T20:59:48+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:48 volumio go-librespot[22821]: time="2026-03-04T20:59:48+07:00" level=debug msg="app state loaded" Mar 04 20:59:48 volumio go-librespot[22821]: time="2026-03-04T20:59:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59: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]" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59: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]" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59: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]" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59:49+07:00" level=info msg="zeroconf server listening on port 37111" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59:49+07:00" level=debug msg="obtained new client token: AADPTFYZ2bUg85kbNlcomuJWQKNW73OIUxeNhaE7LiRtcbDnGgleEMfbLF2SEGXarG6PI9BmYXxY9NEuY/U+0mbrTPIpWI9V3GvqBzEEvkoQgoxWxMB0RutVlb7AyEFjPqnVYlE+YwURLo0nDLv+r/aVuWbeycRphNe2eohKQC0nuB9xAKkrE3sjBMUpHisR7aWc8LKN6vbEU+PNWADSkIdX2le32nI4iIEGh6GLef4T3FHCSDC8Q70pYQ==" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59:49+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59:49+07:00" level=debug msg="completed challenge" Mar 04 20:59:49 volumio go-librespot[22821]: time="2026-03-04T20:59:49+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 " Mar 04 20:59:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:50 volumio volumio[22447]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:50 volumio volumio[22447]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:59:52 volumio volumio[22447]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:59:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 20:59:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:52 volumio go-librespot[22831]: go-librespot daemon starting... Mar 04 20:59:52 volumio go-librespot[22832]: time="2026-03-04T20:59:52+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:52 volumio go-librespot[22832]: time="2026-03-04T20:59:52+07:00" level=debug msg="app state loaded" Mar 04 20:59:52 volumio go-librespot[22832]: time="2026-03-04T20:59:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+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]" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+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]" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=info msg="zeroconf server listening on port 34047" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=debug msg="obtained new client token: AAC7hEhdCr+HSjT7mBb0Ho3gWM5uc+R56S39JrAPkQS8DgQ8JfkD1zQMktI5bd8Vnwff3OowSgdKTAd2XZ+rBQazRAHHtomtKop+Uba0NGGqJS5mncoy2fmACi3Q1DolvA/sUeaxQZs0Utxkq3JKKUJnP3WS1z+S2sNeIA4HfTNEJGD/JGbRY/DfnmBKhX0UPsG/HYZXKp7RGd4k3ADsroxygg5KSIchpuus7wNhlYqIWu/Yxwy8Qfs=" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=debug msg="completed challenge" Mar 04 20:59:53 volumio volumio[22447]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:53 volumio go-librespot[22832]: time="2026-03-04T20:59:53+07:00" level=debug msg="new websocket client" Mar 04 20:59:53 volumio volumio[22447]: info: Connection to go-librespot Websocket established Mar 04 20:59:54 volumio go-librespot[22832]: time="2026-03-04T20:59:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:59:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:54 volumio volumio[22447]: info: Connection to go-librespot Websocket closed Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:59:56 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:56 volumio volumio[22447]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:59:56 volumio volumio[22447]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:59:56 volumio volumio[22447]: info: MyVolumio login type: Token Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:59:56 volumio volumio[22447]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:59:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 20:59:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:59:57 volumio go-librespot[22854]: go-librespot daemon starting... Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+07:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+07:00" level=debug msg="app state loaded" Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+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]" Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+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]" Mar 04 20:59:57 volumio go-librespot[22855]: time="2026-03-04T20:59:57+07:00" level=info msg="zeroconf server listening on port 43453" Mar 04 20:59:57 volumio volumio[22447]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:59:57 volumio volumio[22447]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:59:57 volumio volumio[22447]: info: Streaming services startup Mar 04 20:59:57 volumio volumio[22447]: info: Starting Streaming Daemon Mar 04 20:59:57 volumio sudo[22865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:59:57 volumio sudo[22865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:59:57 volumio volumio[22447]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:59:58 volumio sudo[22865]: pam_unix(sudo:session): session closed for user root Mar 04 20:59:58 volumio volumio[22447]: info: Getting Spotify volume Mar 04 20:59:58 volumio volumio[22447]: info: Initializing connection to go-librespot Websocket Mar 04 20:59:58 volumio volumio[22447]: error: Cannot start Volumio Streaming Daemon Mar 04 20:59:58 volumio volumio[22447]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:59:58 volumio volumio[22447]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:59:58 volumio go-librespot[22855]: time="2026-03-04T20:59:58+07:00" level=debug msg="new websocket client" Mar 04 20:59:58 volumio volumio[22447]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 04 20:59:58 volumio volumio[22447]: info: Connection to go-librespot Websocket established Mar 04 20:59:58 volumio go-librespot[22855]: time="2026-03-04T20:59:58+07:00" level=debug msg="obtained new client token: AACncekDtD5M7DMdGLt9dgv+XFbzTzrPfVnX7FQTNGib/ZwoCdANiDWUuBXUqBZ8czAExdFCEfLrB7014WdUcPgrrzpcrHZE88nfHRBbcUFU3fmg0maXStAFrCOH37Zvn3BWwiFizNyFioMGP5uh9AnwMZ0e1cDFSmQyzwvowM66bSqDqoIaPt+JGMiNDUB4rxNELcyOQrB+YWYYgsg8UONVXSthtKJU42wjY8NMZXSu+RcUfL74Po0=" Mar 04 20:59:58 volumio go-librespot[22855]: time="2026-03-04T20:59:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 04 20:59:58 volumio volumio[22447]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:58 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:58 volumio volumio[22447]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 04 20:59:58 volumio volumio[22447]: SPOTIFY: SPOTIFY VOLUME undefined Mar 04 20:59:58 volumio volumio[22447]: SPOTIFY: VOLUMIO VOLUME 100 Mar 04 20:59:58 volumio volumio[22447]: info: Aligning Spotify Volume to Volumio Volume Mar 04 20:59:58 volumio volumio[22447]: info: CoreCommandRouter::volumioGetState Mar 04 20:59:58 volumio volumio[22447]: info: CorePlayQueue::getTrack 0 Mar 04 20:59:58 volumio volumio[22447]: info: Setting Spotify Volume from Volumio: 100 Mar 04 20:59:58 volumio go-librespot[22855]: time="2026-03-04T20:59:58+07:00" level=debug msg="completed keyexchange" Mar 04 20:59:58 volumio go-librespot[22855]: time="2026-03-04T20:59:58+07:00" level=debug msg="completed challenge" Mar 04 20:59:58 volumio go-librespot[22855]: time="2026-03-04T20:59:58+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 " Mar 04 20:59:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:59:58 volumio volumio[22447]: info: Connection to go-librespot Websocket closed Mar 04 20:59:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:59:58 volumio volumio[22447]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:59:58 volumio volumio[22447]: Error: socket hang up Mar 04 20:59:58 volumio volumio[22447]: at connResetException (node:internal/errors:720:14) Mar 04 20:59:58 volumio volumio[22447]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 04 20:59:58 volumio volumio[22447]: at Socket.emit (node:events:526:35) Mar 04 20:59:58 volumio volumio[22447]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 04 20:59:58 volumio volumio[22447]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 04 20:59:58 volumio volumio[22447]: code: 'ECONNRESET', Mar 04 20:59:58 volumio volumio[22447]: response: undefined Mar 04 20:59:58 volumio volumio[22447]: } Mar 04 20:59:58 volumio volumio[22447]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:59:59 volumio sudo[22885]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:58' Mar 04 20:59:59 volumio sudo[22885]: 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"