Feb 25 03:46:00 volumio sudo[3665]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:46:00 volumio sudo[3665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:00 volumio sudo[3665]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:00 volumio sudo[3684]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:46:00 volumio sudo[3684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:00 volumio sudo[3684]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:00 volumio volumio[3526]: info: Volumio Network Manager: Network status updated: 1 Feb 25 03:46:00 volumio volumio[3526]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:46:00 volumio volumio[3526]: info: CoreStateMachine::pushState Feb 25 03:46:00 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:00 volumio volumio[3526]: info: CoreStateMachine::updateTrackBlock Feb 25 03:46:00 volumio volumio[3526]: info: CorePlayQueue::getTrackBlock Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:46:00 volumio volumio-remote-updater[647]: [2026-02-25 03:46:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771965958 101 Feb 25 03:46:00 volumio volumio[3526]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:00 volumio volumio[3526]: info: Reloading queue from file Feb 25 03:46:00 volumio volumio[3526]: info: CoreStateMachine::setRepeat null single undefined Feb 25 03:46:00 volumio volumio[3526]: info: CoreStateMachine::pushState Feb 25 03:46:00 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:00 volumio volumio[3526]: info: CoreStateMachine::setRandom null Feb 25 03:46:00 volumio volumio[3526]: info: CoreStateMachine::pushState Feb 25 03:46:00 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:00 volumio volumio[3526]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:01 volumio volumio[3526]: info: Setting Device type: Raspberry PI Feb 25 03:46:01 volumio volumio[3526]: info: Completed loading Core Plugins Feb 25 03:46:01 volumio volumio[3526]: info: Preparing to generate the ALSA configuration file Feb 25 03:46:01 volumio volumio[3526]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:46:01 volumio volumio[3526]: info: CoreStateMachine::pushState Feb 25 03:46:01 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:01 volumio volumio[3526]: info: Asound.conf file unchanged, so no further update is needed Feb 25 03:46:01 volumio volumio[3526]: info: Output device has changed, restarting MPD Feb 25 03:46:01 volumio volumio[3526]: info: Output device has changed, restarting Shairport Sync Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:01 volumio sudo[3700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 03:46:01 volumio sudo[3700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:01 volumio sudo[3703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:46:01 volumio sudo[3703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:01 volumio sudo[3704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:46:01 volumio sudo[3703]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:01 volumio sudo[3704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:01 volumio volumio[3526]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:46:01 volumio volumio[3526]: info: ___________ START PLUGINS ___________ Feb 25 03:46:01 volumio sudo[3700]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:01 volumio volumio[3526]: info: ControllerMpd::onStart: Initializing MPD Feb 25 03:46:01 volumio volumio[3526]: info: Creating MPD Configuration file Feb 25 03:46:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 03:46:01 volumio sudo[3713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:01 volumio volumio[3526]: info: [1771965961661] CoreMusicLibrary::Adding element Media Servers Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:01 volumio sudo[3713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:01 volumio sudo[3715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:46:01 volumio volumio[3526]: info: UPNP Browser: Client initialized successfully Feb 25 03:46:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:46:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:46:01 volumio systemd[1]: mpd.service: Consumed 6.944s CPU time. Feb 25 03:46:01 volumio sudo[3713]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:01 volumio sudo[3715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:46:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:46:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:46:01 volumio volumio[3526]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:01 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:46:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:46:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:46:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:46:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:46:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:46:02 volumio volumio[3526]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:02 volumio volumio[3526]: info: [1771965962059] CoreMusicLibrary::Adding element Last_100 Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:02 volumio volumio[3526]: info: [1771965962087] CoreMusicLibrary::Adding element Webradio Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:46:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:46:02 volumio volumio[3526]: info: Initializing BBC Radios Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:02 volumio volumio[3526]: info: Creating Spotify config file Feb 25 03:46:02 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:02 volumio sudo[3729]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 03:46:02 volumio sudo[3729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 03:46:02 volumio sudo[3729]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 25 03:46:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:02 volumio go-librespot[3745]: go-librespot daemon starting... Feb 25 03:46:02 volumio go-librespot[3746]: time="2026-02-25T03:46:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:03 volumio go-librespot[3746]: time="2026-02-25T03:46:03+07:00" level=info msg="zeroconf server listening on port 39999" Feb 25 03:46:04 volumio volumio[3654]: Starting albumart workers Feb 25 03:46:04 volumio volumio[3655]: Starting albumart workers Feb 25 03:46:04 volumio volumio[3526]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:04 volumio volumio[3526]: info: [1771965964604] CoreMusicLibrary::Adding element YouTube Music Feb 25 03:46:04 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:04 volumio volumio[3526]: Cannot find translation for source YouTube Music Feb 25 03:46:04 volumio volumio[3526]: info: Volumio Calling Home Feb 25 03:46:04 volumio sudo[3754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 03:46:04 volumio sudo[3754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:04 volumio volumio[3653]: Starting albumart workers Feb 25 03:46:04 volumio sudo[3754]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:05 volumio volumio[3526]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:46:05 volumio volumio[3526]: info: Discovery: Found device Volumio Feb 25 03:46:05 volumio volumio[3526]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:05 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:05 volumio volumio[3526]: info: MPD Permissions set Feb 25 03:46:05 volumio volumio[3526]: info: MPD Permissions set Feb 25 03:46:05 volumio volumio[3526]: info: Upmpdcli Daemon Started Feb 25 03:46:05 volumio volumio[3526]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:46:05 volumio volumio[3526]: info: Discovery: Found device Volumio Feb 25 03:46:05 volumio volumio[3526]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:05 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:05 volumio volumio[3526]: info: Volumio called home Feb 25 03:46:05 volumio volumio[3526]: info: Spotify config file written Feb 25 03:46:06 volumio sudo[3760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 03:46:06 volumio sudo[3760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:06 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 03:46:06 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 03:46:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:06 volumio go-librespot[3762]: go-librespot daemon starting... Feb 25 03:46:06 volumio sudo[3760]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:06 volumio volumio[3526]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 25 03:46:06 volumio go-librespot[3763]: time="2026-02-25T03:46:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:06 volumio go-librespot[3763]: time="2026-02-25T03:46:06+07:00" level=debug msg="app state loaded" Feb 25 03:46:06 volumio go-librespot[3763]: time="2026-02-25T03:46:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:06 volumio volumio[3526]: info: No need to fix Spotify hosts Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46: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]" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46: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]" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46: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]" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46:07+07:00" level=info msg="zeroconf server listening on port 41481" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46:07+07:00" level=debug msg="obtained new client token: AABqwqz2zaL/7Lco1+hH3z9wojZ8ufj1F+UHtHbTm89k/GXhuD9WGt7KqxW7+GCYqcjnx9MUJ2B2uiyXpPjteqIN1fJYjjtwAL9hAnHm8BlsTqTLx6O1bT4HA9lU0Aw48HOAYwkiN3m24Y2QO0tkvDgYVoAMMuHJLpNzbppoT4bKhfkq+HL/d+UDEgSgX7/UjX+Zc4JyVmmz3/BleG37j3C9SVCG7A/IEeDBs9oNOcImKO+t4as09esf9Q==" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46:07+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46:07+07:00" level=debug msg="completed challenge" Feb 25 03:46:07 volumio go-librespot[3763]: time="2026-02-25T03:46:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:07 volumio volumio[3526]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:46:07 volumio volumio[3526]: SPOTIFY: BQDuNRIPWSErreONw6RTfJpFNJJwohxnobz8vGS9bQQPR5CPF9ckpue72lfrtdTx9WumqCni3O5p1VJ6L03QBEzrlErechdLhOHKYdKAybUQFPtW40N54Jp5szgJOgU1FnhuncWTquG_TyHdYHbSdDL8P22b6X5PPovEekLTnfdYY7pV_hSuA5HqrKGoJxZpfUDd_W2m7gEDPEXaJ-E8C0SL5doN0gl8i8vkDP7ZFiC7u9_Qk4p8XzbM7uvoqstDjIq42V01ctLaMhSdQDdf6_H0NqSyPrp56Ws9DmAwULlMrZr3qT4xdCpi Feb 25 03:46:07 volumio volumio[3526]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:46:08 volumio volumio[3526]: info: New Spotify access token = BQDuNRIPWSErreONw6RTfJpFNJJwohxnobz8vGS9bQQPR5CPF9ckpue72lfrtdTx9WumqCni3O5p1VJ6L03QBEzrlErechdLhOHKYdKAybUQFPtW40N54Jp5szgJOgU1FnhuncWTquG_TyHdYHbSdDL8P22b6X5PPovEekLTnfdYY7pV_hSuA5HqrKGoJxZpfUDd_W2m7gEDPEXaJ-E8C0SL5doN0gl8i8vkDP7ZFiC7u9_Qk4p8XzbM7uvoqstDjIq42V01ctLaMhSdQDdf6_H0NqSyPrp56Ws9DmAwULlMrZr3qT4xdCpi Feb 25 03:46:08 volumio volumio[3526]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 03:46:08 volumio volumio[3526]: info: Starting Shairport Sync Feb 25 03:46:08 volumio volumio[3526]: info: Starting Shairport Sync Feb 25 03:46:08 volumio volumio[3526]: info: Starting Shairport Sync Feb 25 03:46:08 volumio sudo[3801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:46:08 volumio sudo[3801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:08 volumio sudo[3803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:46:08 volumio sudo[3803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:08 volumio sudo[3807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:46:08 volumio sudo[3807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:46:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:46:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:46:08 volumio systemd[1]: shairport-sync.service: Consumed 2.259s CPU time. Feb 25 03:46:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:46:08 volumio sudo[3801]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:08 volumio sudo[3807]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:08 volumio sudo[3803]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:08 volumio volumio[3526]: info: Shairport-Sync Started Feb 25 03:46:08 volumio volumio[3526]: Error adding Membership: Error: addMembership EINVAL Feb 25 03:46:08 volumio volumio[3526]: info: Shairport-Sync Started Feb 25 03:46:08 volumio volumio[3526]: info: Shairport-Sync Started Feb 25 03:46:08 volumio volumio[3526]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:08 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:09 volumio volumio[3526]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 25 03:46:09 volumio volumio[3526]: info: Spotify Successfully logged in Feb 25 03:46:09 volumio volumio[3526]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:09 volumio volumio[3526]: info: [1771965969087] CoreMusicLibrary::Adding element Spotify Feb 25 03:46:09 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:09 volumio volumio[3526]: Cannot find translation for source YouTube Music Feb 25 03:46:09 volumio volumio[3526]: Cannot find translation for source Spotify Feb 25 03:46:09 volumio mpd[3744]: 2026-02-25T03:46:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 03:46:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 03:46:09 volumio sudo[3715]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:09 volumio sudo[3704]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:10 volumio volumio[3526]: error: MPD error: The expression evaluated to a falsy value: Feb 25 03:46:10 volumio volumio[3526]: assert.ok(self.idling) Feb 25 03:46:10 volumio volumio[3526]: error: The expression evaluated to a falsy value: Feb 25 03:46:10 volumio volumio[3526]: assert.ok(self.idling) Feb 25 03:46:10 volumio volumio[3526]: error: updateQueue error: null Feb 25 03:46:10 volumio volumio[3526]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 03:46:10 volumio volumio[3526]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:46:10 volumio volumio[3526]: info: MPD running with PID3744 Feb 25 03:46:10 volumio volumio[3526]: ,establishing connection Feb 25 03:46:10 volumio volumio[3526]: error: updateQueue error: null Feb 25 03:46:10 volumio volumio[3526]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:46:10 volumio volumio[3526]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:10 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:10 volumio volumio[3526]: info: CoreStateMachine::pushState Feb 25 03:46:10 volumio volumio[3526]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:10 volumio volumio[3526]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:10 volumio volumio[3526]: info: Completed starting Core Plugins Feb 25 03:46:10 volumio volumio[3526]: info: ------------------------------------------- Feb 25 03:46:10 volumio volumio[3526]: info: ----- MyVolumio plugins startup ---- Feb 25 03:46:10 volumio volumio[3526]: info: ------------------------------------------- Feb 25 03:46:10 volumio volumio[3526]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 03:46:10 volumio volumio[3526]: info: go-librespot daemon successfully initialized Feb 25 03:46:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 03:46:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:11 volumio go-librespot[3846]: go-librespot daemon starting... Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=debug msg="app state loaded" Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:46:11 volumio go-librespot[3847]: time="2026-02-25T03:46:11+07:00" level=info msg="zeroconf server listening on port 37355" Feb 25 03:46:12 volumio go-librespot[3847]: time="2026-02-25T03:46:12+07:00" level=debug msg="obtained new client token: AADXYhD5EBYEC/Igp6vN8Sz0d1yC5s70a0jcP48DrbWGf2j+Ei9RP9i2DyBELH+rhvF+SEsB+rCSmwr5/FAtloSLXEgu5AVet/gjKjjB9VrhK8XApy37GMxmuEW+/l7Tns7MHN+gJRBdi+0VTO9mrMOSjPcvfsCZ1t9z8Ebdk2xyxqr+XiFFAtoO2UsxqT02u1ZpmqBKgWdDQOLYoEPvDgvhcyMjDSr09f26dQGF64NVrUgyzy/r" Feb 25 03:46:12 volumio go-librespot[3847]: time="2026-02-25T03:46:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:12 volumio go-librespot[3847]: time="2026-02-25T03:46:12+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:12 volumio go-librespot[3847]: time="2026-02-25T03:46:12+07:00" level=debug msg="completed challenge" Feb 25 03:46:12 volumio go-librespot[3847]: time="2026-02-25T03:46:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:13 volumio volumio[3526]: info: Initializing connection to go-librespot Websocket Feb 25 03:46:13 volumio volumio[3526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:46:14 volumio volumio[3526]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 03:46:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 03:46:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:15 volumio go-librespot[3854]: go-librespot daemon starting... Feb 25 03:46:15 volumio go-librespot[3855]: time="2026-02-25T03:46:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:15 volumio go-librespot[3855]: time="2026-02-25T03:46:15+07:00" level=debug msg="app state loaded" Feb 25 03:46:15 volumio go-librespot[3855]: time="2026-02-25T03:46:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=info msg="zeroconf server listening on port 38693" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="obtained new client token: AAD1rKnGtYFhvVEZkezWf0PlXAs2BzCI72oPWwWCO+83o1uhrh8uzF64utXNcBdjpwqrgipMJdADMGBd4pEO+bMlerYVR3P+9nsN07UTdK/riZnkH12kSVRwpaCmbdweNyOELnyZ3gXkMHSKU3rtXAaUJ9gtb3aUJzGSOqkZUz2pHOSvDEyZ2N2XdyoUv8spY4V6Mx234P6iBB0BNHIa4WwGmeAMkO07WTUjhj3RLSLABSGAsPXGJHsZQA==" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="completed challenge" Feb 25 03:46:16 volumio volumio[3526]: info: Initializing connection to go-librespot Websocket Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=debug msg="new websocket client" Feb 25 03:46:16 volumio volumio[3526]: info: Connection to go-librespot Websocket established Feb 25 03:46:16 volumio go-librespot[3855]: time="2026-02-25T03:46:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:16 volumio volumio[3526]: info: Connection to go-librespot Websocket closed Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 03:46:19 volumio volumio[3526]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 03:46:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 03:46:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:20 volumio go-librespot[3877]: go-librespot daemon starting... Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=debug msg="app state loaded" Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:20 volumio go-librespot[3878]: time="2026-02-25T03:46:20+07:00" level=info msg="zeroconf server listening on port 40185" Feb 25 03:46:21 volumio go-librespot[3878]: time="2026-02-25T03:46:21+07:00" level=debug msg="obtained new client token: AACGH8st/75s5nSKTaaKot7TlrS/tnjpFTuFDG84A3CgMj370XOt9vOQ4QqQbecNWiFg0R3yp3EwA0FuKB09eAL7Q3nuQWHeES1DH1xYhrhJYgtNIreAqJ94pfR1ITg6Faurd3w8S8xIxTvyYSwrlYWTegwLaH3IFRCLC2dr3LxVNUCwVIVIN0OkCU+2D5M3mFjQWyQU6ac5WTlXKIBkic6qFFmgakp+ERrgYSoQATNYk/6E+EEV7qQ=" Feb 25 03:46:21 volumio go-librespot[3878]: time="2026-02-25T03:46:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 25 03:46:21 volumio volumio[3526]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 03:46:21 volumio volumio[3526]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 03:46:21 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:21 volumio volumio[3526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:21 volumio volumio[3526]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 03:46:21 volumio go-librespot[3878]: time="2026-02-25T03:46:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 03:46:21 volumio volumio[3526]: info: MyVolumio login type: Token Feb 25 03:46:21 volumio volumio[3526]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 03:46:21 volumio volumio[3526]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 03:46:21 volumio go-librespot[3878]: time="2026-02-25T03:46:21+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:21 volumio go-librespot[3878]: time="2026-02-25T03:46:21+07:00" level=debug msg="completed challenge" Feb 25 03:46:21 volumio go-librespot[3878]: time="2026-02-25T03:46:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:23 volumio volumio[3526]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 03:46:23 volumio volumio[3526]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 03:46:23 volumio volumio[3526]: info: Streaming services startup Feb 25 03:46:23 volumio volumio[3526]: info: Starting Streaming Daemon Feb 25 03:46:23 volumio sudo[3886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 03:46:23 volumio sudo[3886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:23 volumio volumio[3526]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 03:46:23 volumio sudo[3886]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:23 volumio volumio[3526]: info: Getting Spotify volume Feb 25 03:46:23 volumio volumio[3526]: info: Initializing connection to go-librespot Websocket Feb 25 03:46:23 volumio volumio[3526]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:46:23 volumio volumio[3526]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:46:23 volumio volumio[3526]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 03:46:23 volumio volumio[3526]: errno: -111, Feb 25 03:46:23 volumio volumio[3526]: code: 'ECONNREFUSED', Feb 25 03:46:23 volumio volumio[3526]: syscall: 'connect', Feb 25 03:46:23 volumio volumio[3526]: address: '127.0.0.1', Feb 25 03:46:23 volumio volumio[3526]: port: 9879, Feb 25 03:46:23 volumio volumio[3526]: response: undefined Feb 25 03:46:23 volumio volumio[3526]: } Feb 25 03:46:23 volumio volumio[3526]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:46:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 03:46:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:24 volumio go-librespot[3904]: go-librespot daemon starting... Feb 25 03:46:24 volumio go-librespot[3905]: time="2026-02-25T03:46:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:24 volumio go-librespot[3905]: time="2026-02-25T03:46:24+07:00" level=debug msg="app state loaded" Feb 25 03:46:24 volumio go-librespot[3905]: time="2026-02-25T03:46:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:24 volumio sudo[3914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 03:45' Feb 25 03:46:24 volumio sudo[3914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:25 volumio sudo[3914]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=info msg="zeroconf server listening on port 37983" Feb 25 03:46:25 volumio volumio-remote-updater[647]: [2026-02-25 03:46:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 25 03:46:25 volumio volumio-remote-updater[647]: [2026-02-25 03:46:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 25 03:46:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 25 03:46:25 volumio systemd[1]: volumio.service: Consumed 53.923s CPU time. Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="obtained new client token: AADNHZFRtp8mOWwcLiKMbYX2v8N2iRmW4qj7haItjF87FCzDskQ9C4q+EahKVi+jtehLlcUpjlqY5lIFMA7spPMnSvprJ0ctX1oT1y7xRL7iiai2dEFepoCJM5QjY0jsw4eXdzf+cKuaNQC8qbplTKGAhwA1wRzTmDNTpl+D2CwplUEq5sW/oP9uokHZinFGU8GRPxkXgoNVpEgDt9LslzOm5L8GviPDZR8Ml4X5izxF3rYEtstdWLh+Yg==" Feb 25 03:46:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:46:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:46:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7500. Feb 25 03:46:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:46:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 25 03:46:25 volumio systemd[1]: volumio.service: Consumed 53.923s CPU time. Feb 25 03:46:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=debug msg="completed challenge" Feb 25 03:46:25 volumio go-librespot[3905]: time="2026-02-25T03:46:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 25 03:46:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:29 volumio go-librespot[3945]: go-librespot daemon starting... Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=debug msg="app state loaded" Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:29 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:29 volumio volumio[3927]: info: ----- Volumio3 ---- Feb 25 03:46:29 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:29 volumio volumio[3927]: info: ----- System startup ---- Feb 25 03:46:29 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=info msg="zeroconf server listening on port 39777" Feb 25 03:46:29 volumio go-librespot[3949]: time="2026-02-25T03:46:29+07:00" level=debug msg="obtained new client token: AABNl8yXbtRnG6M7rnlaWkxr0k5nFoZgRh6iPFEBAZtwXZ1tG/Kk+F1g7xAkz4xadj+NXMUsxWffGbLzLGkzDBdM/wtkXgqnvhQam6MRM4KZettr6FdZ38apLdXraaxscfrNfUyN822kVpY16k9EhA0KdXKpyT2hHdAIszK1gMdc/ZLIlWYdV0NYBVRYe0d0Eiq1lZxWZyRdEH6Zosvk5tQA86p16ksgYZVZKjPMUvcy5pDKxx1iFX/LtA==" Feb 25 03:46:30 volumio go-librespot[3949]: time="2026-02-25T03:46:30+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 25 03:46:30 volumio go-librespot[3949]: time="2026-02-25T03:46:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 03:46:30 volumio go-librespot[3949]: time="2026-02-25T03:46:30+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:30 volumio go-librespot[3949]: time="2026-02-25T03:46:30+07:00" level=debug msg="completed challenge" Feb 25 03:46:30 volumio go-librespot[3949]: time="2026-02-25T03:46:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:30 volumio volumio-remote-updater[647]: [2026-02-25 03:46:30] [connect] Successful connection Feb 25 03:46:30 volumio volumio[3927]: info: MYVOLUMIO Environment detected Feb 25 03:46:30 volumio volumio[3927]: info: Plugin folders cleanup Feb 25 03:46:30 volumio volumio[3927]: info: Scanning into folder /volumio/app/plugins/ Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category audio_interface Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category miscellanea Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category music_service Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category plugins.json Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category system_controller Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category user_interface Feb 25 03:46:30 volumio volumio[3927]: info: Scanning into folder /data/plugins/ Feb 25 03:46:30 volumio volumio[3927]: info: Scanning category music_service Feb 25 03:46:30 volumio volumio[3927]: info: Plugin folders cleanup completed Feb 25 03:46:30 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:30 volumio volumio[3927]: info: ----- Core plugins startup ---- Feb 25 03:46:30 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:30 volumio volumio[3927]: info: Loading plugins from folder /volumio/app/plugins/ Feb 25 03:46:30 volumio volumio[3927]: info: Adding plugin upnp to MyMusic Plugins Feb 25 03:46:31 volumio volumio[3927]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 25 03:46:31 volumio volumio[3927]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 25 03:46:31 volumio volumio[3927]: info: Loading plugins from folder /data/plugins/ Feb 25 03:46:31 volumio volumio[3927]: info: Loading plugin "system"... Feb 25 03:46:31 volumio volumio[3927]: info: Loading plugin "appearance"... Feb 25 03:46:32 volumio volumio[3927]: info: Loading plugin "network"... Feb 25 03:46:33 volumio volumio[3927]: info: Refreshing Cached IP Addresses Feb 25 03:46:33 volumio sudo[3966]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:46:33 volumio sudo[3966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:33 volumio sudo[3968]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:46:33 volumio sudo[3966]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:33 volumio sudo[3968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:33 volumio sudo[3968]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "services"... Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "alsa_controller"... Feb 25 03:46:33 volumio sudo[3977]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 03:46:33 volumio sudo[3977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:33 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "wizard"... Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "networkfs"... Feb 25 03:46:33 volumio volumio[3927]: info: Starting Udev Watcher for removable devices Feb 25 03:46:33 volumio volumio[3927]: info: Ignoring mount for partition: boot Feb 25 03:46:33 volumio volumio[3927]: info: Ignoring mount for partition: volumio Feb 25 03:46:33 volumio volumio[3927]: info: Ignoring mount for partition: volumio_data Feb 25 03:46:33 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "volumio_command_line_client"... Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "upnp"... Feb 25 03:46:33 volumio volumio[3927]: info: [1771965993436] Starting Upmpd Daemon Feb 25 03:46:33 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "my_music"... Feb 25 03:46:33 volumio volumio[3927]: info: Loading plugin "mpd"... Feb 25 03:46:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 25 03:46:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:33 volumio go-librespot[3999]: go-librespot daemon starting... Feb 25 03:46:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:33 volumio go-librespot[4000]: time="2026-02-25T03:46:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:33 volumio go-librespot[4000]: time="2026-02-25T03:46:33+07:00" level=debug msg="app state loaded" Feb 25 03:46:33 volumio go-librespot[4000]: time="2026-02-25T03:46:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:34 volumio volumio[3927]: info: Loading plugin "upnp_browser"... Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=info msg="zeroconf server listening on port 45755" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="obtained new client token: AAARuv1P3aA6OZsy2W4g5XRB59VC52AwMwuzpdiOONaA4U15wxcku9O4ChUUokpknVzOlMe4OR5VTLjwA7FiVGVISv2/6ZHXJaiWIaL4QbUyIYqL/xukTcPWZyOxoQIvWisrp7dUiHoTPb9dQ3zcR/Nn5L3XC0TadfB0fKB112zsHMl37oYIiUaI11KafvWTFcTPJGzLbqzY5mzmXyV8HZX4ZeNx7+QHFnNynzfXfhQnVujj9HB2b3KmKQ==" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=debug msg="completed challenge" Feb 25 03:46:34 volumio go-librespot[4000]: time="2026-02-25T03:46:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:35 volumio sudo[3977]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:37 volumio volumio[3927]: info: Starting UPNP Browser Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "alarm-clock"... Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "airplay_emulation"... Feb 25 03:46:37 volumio volumio[3927]: info: Starting Shairport Sync Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "last_100"... Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "webradio"... Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "i2s_dacs"... Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "volumiodiscovery"... Feb 25 03:46:37 volumio volumio[3927]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:46:37 volumio volumio[3927]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:46:37 volumio volumio[3927]: *** WARNING *** For more information see Feb 25 03:46:37 volumio volumio[3927]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:46:37 volumio volumio[3927]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:46:37 volumio volumio[3927]: *** WARNING *** For more information see Feb 25 03:46:37 volumio node[3927]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:46:37 volumio node[3927]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:46:37 volumio node[3927]: *** WARNING *** For more information see Feb 25 03:46:37 volumio node[3927]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:46:37 volumio node[3927]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:46:37 volumio node[3927]: *** WARNING *** For more information see Feb 25 03:46:37 volumio volumio[3927]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 25 03:46:37 volumio volumio[3927]: info: Discovery: Started advertising with name: Volumio Feb 25 03:46:37 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:46:37 volumio volumio[3927]: info: Loading plugin "spop"... Feb 25 03:46:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 25 03:46:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:38 volumio go-librespot[4010]: go-librespot daemon starting... Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=debug msg="app state loaded" Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:38 volumio go-librespot[4011]: time="2026-02-25T03:46:38+07:00" level=info msg="zeroconf server listening on port 38073" Feb 25 03:46:39 volumio go-librespot[4011]: time="2026-02-25T03:46:39+07:00" level=debug msg="obtained new client token: AABLbdvxVLWpgK++5W11UBgcfen5X14bLjuoTt6u5kmAguGYK1jgZeCfvw0+k5Cyd0qXgMBLoZJRMOGKu2MECsMZVOdb9/J0HxnbtjYz7KTaTpT5EwbbcRDqnM4CQv4eq6FDoa3STZSLj4eUaPHXZPaqOOEjI4UB6oAduLziM8yS6b6T1BYMDNJE6fDSZnUE0WH0bDL5DjkktcAHWYyXd9A80vbeBbmbwECLzYmLdGz+m2PyK4w8HHo=" Feb 25 03:46:39 volumio go-librespot[4011]: time="2026-02-25T03:46:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:39 volumio go-librespot[4011]: time="2026-02-25T03:46:39+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:39 volumio go-librespot[4011]: time="2026-02-25T03:46:39+07:00" level=debug msg="completed challenge" Feb 25 03:46:39 volumio go-librespot[4011]: time="2026-02-25T03:46:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:39 volumio volumio[3927]: info: Loading plugin "ytcr"... Feb 25 03:46:42 volumio volumio[3927]: info: Loading plugin "ytmusic"... Feb 25 03:46:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 25 03:46:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:42 volumio go-librespot[4018]: go-librespot daemon starting... Feb 25 03:46:42 volumio go-librespot[4019]: time="2026-02-25T03:46:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:42 volumio go-librespot[4019]: time="2026-02-25T03:46:42+07:00" level=debug msg="app state loaded" Feb 25 03:46:42 volumio go-librespot[4019]: time="2026-02-25T03:46:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:42 volumio volumio-remote-updater[647]: [2026-02-25 03:46:42] [connect] Successful connection Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=info msg="zeroconf server listening on port 46005" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="obtained new client token: AACuZu9RU5CYzrNATA/iIvCikebG1v46wxTKR3IWr3aN1RdnlESTYWK/WfENwUW5J3JUw+1zjFBxECSpXcFLhwIyrEovRRr2C2jxmhobReXQW3XjOGkJIigceSTISzUnZooxfOMpe1RGPOGzal2EYOA94+KkrtaO1xYlltd59V1j0Y3yupZQazstQLYNGm6BV4OBVVnZJvJx1Y0/kJYsAJaVjzheCOe7snm2UDlVgvj/SMvGnm+nVNRGWg==" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 25 03:46:43 volumio volumio[3927]: info: Loading plugin "outputs"... Feb 25 03:46:43 volumio volumio[3927]: info: Loading plugin "albumart"... Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 03:46:43 volumio volumio[3927]: info: Plugin example_plugin is not enabled Feb 25 03:46:43 volumio volumio[3927]: info: Loading plugin "inputs"... Feb 25 03:46:43 volumio volumio[3927]: info: Loading plugin "updater_comm"... Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=debug msg="completed challenge" Feb 25 03:46:43 volumio go-librespot[4019]: time="2026-02-25T03:46:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:44 volumio volumio[3927]: info: Plugin mpdemulation is not enabled Feb 25 03:46:44 volumio volumio[3927]: info: Loading plugin "rest_api"... Feb 25 03:46:44 volumio volumio[3927]: info: Loading plugin "websocket"... Feb 25 03:46:44 volumio volumio[3927]: info: Starting Socket.io Server version 1.7.4 Feb 25 03:46:44 volumio volumio[3927]: info: Loading plugin "RoonBridge"... Feb 25 03:46:44 volumio volumio[3927]: info: Applying required configuration parameters for plugin RoonBridge Feb 25 03:46:44 volumio volumio[3927]: info: Loading i18n strings for locale en Feb 25 03:46:44 volumio volumio[3927]: Updating browse sources language Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::initPlayerControls Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:46:44 volumio volumio[3927]: Express server listening on port 3000 Feb 25 03:46:44 volumio volumio[3927]: [Metrics] WebUI: 16s 560.05ms Feb 25 03:46:44 volumio volumio[3927]: info: CoreStateMachine::resetVolumioState Feb 25 03:46:44 volumio volumio[3927]: info: CoreStateMachine::getcurrentVolume Feb 25 03:46:44 volumio volumio[3927]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:46:44 volumio volumio[4042]: Forking 3 albumart workers Feb 25 03:46:45 volumio sudo[4058]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:46:45 volumio sudo[4058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:45 volumio sudo[4058]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:45 volumio sudo[4062]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:46:45 volumio sudo[4062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:45 volumio volumio[3927]: info: Volumio Network Manager: Network status updated: 1 Feb 25 03:46:45 volumio sudo[4062]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:45 volumio volumio[3927]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:46:45 volumio volumio[3927]: info: CoreStateMachine::pushState Feb 25 03:46:45 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:45 volumio volumio[3927]: info: CoreStateMachine::updateTrackBlock Feb 25 03:46:45 volumio volumio[3927]: info: CorePlayQueue::getTrackBlock Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:46:45 volumio volumio-remote-updater[647]: [2026-02-25 03:46:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771966002 101 Feb 25 03:46:45 volumio volumio[3927]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:45 volumio volumio[3927]: info: Reloading queue from file Feb 25 03:46:45 volumio volumio[3927]: info: CoreStateMachine::setRepeat null single undefined Feb 25 03:46:45 volumio volumio[3927]: info: CoreStateMachine::pushState Feb 25 03:46:45 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:45 volumio volumio[3927]: info: CoreStateMachine::setRandom null Feb 25 03:46:45 volumio volumio[3927]: info: CoreStateMachine::pushState Feb 25 03:46:45 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:45 volumio volumio[3927]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:45 volumio volumio[3927]: info: Setting Device type: Raspberry PI Feb 25 03:46:45 volumio volumio[3927]: info: Completed loading Core Plugins Feb 25 03:46:45 volumio volumio[3927]: info: Preparing to generate the ALSA configuration file Feb 25 03:46:46 volumio volumio[3927]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:46:46 volumio volumio[3927]: info: CoreStateMachine::pushState Feb 25 03:46:46 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:46 volumio volumio[3927]: info: Asound.conf file unchanged, so no further update is needed Feb 25 03:46:46 volumio volumio[3927]: info: Output device has changed, restarting MPD Feb 25 03:46:46 volumio sudo[4102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 03:46:46 volumio volumio[3927]: info: Output device has changed, restarting Shairport Sync Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:46 volumio sudo[4102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:46 volumio sudo[4105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:46:46 volumio sudo[4105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:46 volumio sudo[4105]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:46 volumio sudo[4106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:46:46 volumio sudo[4106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:46 volumio volumio[3927]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:46:46 volumio volumio[3927]: info: ___________ START PLUGINS ___________ Feb 25 03:46:46 volumio volumio[3927]: info: ControllerMpd::onStart: Initializing MPD Feb 25 03:46:46 volumio volumio[3927]: info: Creating MPD Configuration file Feb 25 03:46:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 03:46:46 volumio sudo[4102]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:46 volumio volumio[3927]: info: [1771966006525] CoreMusicLibrary::Adding element Media Servers Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:46 volumio sudo[4115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:46:46 volumio sudo[4115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:46 volumio volumio[3927]: info: UPNP Browser: Client initialized successfully Feb 25 03:46:46 volumio sudo[4117]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:46:46 volumio sudo[4117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:46:46 volumio sudo[4115]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:46:46 volumio systemd[1]: mpd.service: Consumed 6.917s CPU time. Feb 25 03:46:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:46:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:46:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:46:46 volumio volumio[3927]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:46:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:46:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:46:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:46:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:46:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:46:46 volumio volumio[3927]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:46 volumio volumio[3927]: info: [1771966006890] CoreMusicLibrary::Adding element Last_100 Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:46 volumio volumio[3927]: info: [1771966006908] CoreMusicLibrary::Adding element Webradio Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:46 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:46:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:46:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:46:46 volumio volumio[3927]: info: Initializing BBC Radios Feb 25 03:46:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 25 03:46:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:47 volumio go-librespot[4133]: go-librespot daemon starting... Feb 25 03:46:47 volumio go-librespot[4135]: time="2026-02-25T03:46:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:47 volumio go-librespot[4135]: time="2026-02-25T03:46:47+07:00" level=debug msg="app state loaded" Feb 25 03:46:47 volumio go-librespot[4135]: time="2026-02-25T03:46:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:47 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:46:47 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:47 volumio volumio[3927]: info: Creating Spotify config file Feb 25 03:46:47 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:47 volumio sudo[4131]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 03:46:47 volumio sudo[4131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 03:46:47 volumio sudo[4131]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:47 volumio go-librespot[4135]: time="2026-02-25T03:46:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:46:47 volumio go-librespot[4135]: time="2026-02-25T03:46:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:46:47 volumio go-librespot[4135]: time="2026-02-25T03:46:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:46:48 volumio go-librespot[4135]: time="2026-02-25T03:46:48+07:00" level=info msg="zeroconf server listening on port 46837" Feb 25 03:46:48 volumio go-librespot[4135]: time="2026-02-25T03:46:48+07:00" level=debug msg="obtained new client token: AADtkbeE+uihnIkYzoSaAO3wUsf0X1xgVm9BYW9m+NZ6DeIDhmtwWqI7Cs13se+F1/+ZJoVWHrVqt6kMkW+NbhSQUb/UOLDm4A+L/k7bzz1JpiWmjS7BXCovXIQsOHrFHb7eibyhO0c+4crYVNDut6r/dWD0jDYPzXo+IDHNBCpj3lFF9u1/G1bonUTlvv9coJnUlnfUFIOwHwPuQhXPzyZTtZm4RPk0aYjJ93uJNgHPbnP0AfXrG9wvMA==" Feb 25 03:46:48 volumio go-librespot[4135]: time="2026-02-25T03:46:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:48 volumio go-librespot[4135]: time="2026-02-25T03:46:48+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:48 volumio go-librespot[4135]: time="2026-02-25T03:46:48+07:00" level=debug msg="completed challenge" Feb 25 03:46:48 volumio go-librespot[4135]: time="2026-02-25T03:46:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:49 volumio volumio[4059]: Starting albumart workers Feb 25 03:46:49 volumio volumio[3927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:49 volumio volumio[3927]: info: [1771966009449] CoreMusicLibrary::Adding element YouTube Music Feb 25 03:46:49 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:49 volumio volumio[3927]: Cannot find translation for source YouTube Music Feb 25 03:46:49 volumio volumio[3927]: info: Volumio Calling Home Feb 25 03:46:49 volumio sudo[4156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 03:46:49 volumio sudo[4156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:49 volumio sudo[4156]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:50 volumio volumio[4061]: Starting albumart workers Feb 25 03:46:50 volumio volumio[4056]: Starting albumart workers Feb 25 03:46:50 volumio volumio[3927]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:46:50 volumio volumio[3927]: info: Discovery: Found device Volumio Feb 25 03:46:50 volumio volumio[3927]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:50 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:50 volumio volumio[3927]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:46:50 volumio volumio[3927]: info: Discovery: Found device Volumio Feb 25 03:46:50 volumio volumio[3927]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:50 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:50 volumio volumio[3927]: info: MPD Permissions set Feb 25 03:46:50 volumio volumio[3927]: info: MPD Permissions set Feb 25 03:46:50 volumio volumio[3927]: info: Upmpdcli Daemon Started Feb 25 03:46:51 volumio volumio[3927]: info: Spotify config file written Feb 25 03:46:51 volumio sudo[4163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 03:46:51 volumio sudo[4163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:51 volumio go-librespot[4165]: go-librespot daemon starting... Feb 25 03:46:51 volumio volumio[3927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 25 03:46:51 volumio sudo[4163]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio go-librespot[4166]: time="2026-02-25T03:46:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:51 volumio go-librespot[4166]: time="2026-02-25T03:46:51+07:00" level=debug msg="app state loaded" Feb 25 03:46:51 volumio go-librespot[4166]: time="2026-02-25T03:46:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:46:51 volumio volumio[3927]: info: No need to fix Spotify hosts Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=info msg="zeroconf server listening on port 36869" Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="obtained new client token: AABVopsDNJRm9fZ7bd2CBUcLyTdS3+Y1OmPRDynUwBf6H29oXafpAOrCI8TG2aq/sdKxXtZUuq90xe8Y7gt0OLgBqtW5GuH33qNx7hUDYsilp/SF1e+CYHhBb5/PBhi3DhbNyrKffOhy+udzRWYJyACLL8RWzKKEvyra5DlCVSYBGS9uLHbs8/+L5841GIUerTIWMTWwqGfEnvjv5Yx+i3SVgtCd8QaU3we0N6Fi5KQ8htiInwM7un93nA==" Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:52 volumio volumio[3927]: info: Volumio called home Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:52 volumio go-librespot[4166]: time="2026-02-25T03:46:52+07:00" level=debug msg="completed challenge" Feb 25 03:46:53 volumio go-librespot[4166]: time="2026-02-25T03:46:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:53 volumio volumio[3927]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:46:53 volumio volumio[3927]: SPOTIFY: BQA76chGsDt09MBmQqtF4nEDLiiW4pJIEJq2tBghAhi-1p52s_5yOJlX-fWg_DjhFRlCGE1cp4qvxabKTLKkr9DufPYWDFfqhC9Cjmh4voBZPUN6G65LQ4Yxt3ONih1YaXwxbw7FXaKgJFMPpu8Mtrd_FnUFnw4ufHO4PzU7S_RSb8qFA3imB14tPOIU1AuFhmCxyXYk5JqhvpdphJdLPsYC0ZDeeRSCHPMFrxW__srakorVoee_SHD4CeBBFWQR3p0btG0zw03w54wkHT6QXbx1q4t-8Z1_XpbtrNH-tbw-cxZJo4QzRhe9 Feb 25 03:46:53 volumio volumio[3927]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:46:53 volumio volumio[3927]: info: New Spotify access token = BQA76chGsDt09MBmQqtF4nEDLiiW4pJIEJq2tBghAhi-1p52s_5yOJlX-fWg_DjhFRlCGE1cp4qvxabKTLKkr9DufPYWDFfqhC9Cjmh4voBZPUN6G65LQ4Yxt3ONih1YaXwxbw7FXaKgJFMPpu8Mtrd_FnUFnw4ufHO4PzU7S_RSb8qFA3imB14tPOIU1AuFhmCxyXYk5JqhvpdphJdLPsYC0ZDeeRSCHPMFrxW__srakorVoee_SHD4CeBBFWQR3p0btG0zw03w54wkHT6QXbx1q4t-8Z1_XpbtrNH-tbw-cxZJo4QzRhe9 Feb 25 03:46:53 volumio volumio[3927]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 03:46:53 volumio volumio[3927]: info: Starting Shairport Sync Feb 25 03:46:53 volumio volumio[3927]: info: Starting Shairport Sync Feb 25 03:46:53 volumio volumio[3927]: info: Starting Shairport Sync Feb 25 03:46:53 volumio sudo[4203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:46:53 volumio sudo[4203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:53 volumio sudo[4212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:46:53 volumio sudo[4212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:53 volumio sudo[4209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:46:53 volumio sudo[4209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:46:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:46:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:46:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:46:53 volumio systemd[1]: shairport-sync.service: Consumed 2.168s CPU time. Feb 25 03:46:53 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:46:53 volumio sudo[4203]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:46:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:46:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:46:53 volumio volumio[3927]: info: Shairport-Sync Started Feb 25 03:46:53 volumio volumio[3927]: Error adding Membership: Error: addMembership EINVAL Feb 25 03:46:53 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:46:53 volumio volumio[3927]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:53 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:53 volumio sudo[4212]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:53 volumio sudo[4209]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:54 volumio volumio[3927]: info: Shairport-Sync Started Feb 25 03:46:54 volumio volumio[3927]: info: Shairport-Sync Started Feb 25 03:46:54 volumio volumio[3927]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 25 03:46:54 volumio volumio[3927]: info: Spotify Successfully logged in Feb 25 03:46:54 volumio volumio[3927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:46:54 volumio volumio[3927]: info: [1771966014244] CoreMusicLibrary::Adding element Spotify Feb 25 03:46:54 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:46:54 volumio volumio[3927]: Cannot find translation for source YouTube Music Feb 25 03:46:54 volumio volumio[3927]: Cannot find translation for source Spotify Feb 25 03:46:54 volumio mpd[4154]: 2026-02-25T03:46:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 03:46:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 03:46:54 volumio sudo[4106]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:54 volumio sudo[4117]: pam_unix(sudo:session): session closed for user root Feb 25 03:46:54 volumio volumio[3927]: error: MPD error: The expression evaluated to a falsy value: Feb 25 03:46:54 volumio volumio[3927]: assert.ok(self.idling) Feb 25 03:46:54 volumio volumio[3927]: error: The expression evaluated to a falsy value: Feb 25 03:46:54 volumio volumio[3927]: assert.ok(self.idling) Feb 25 03:46:54 volumio volumio[3927]: error: updateQueue error: null Feb 25 03:46:54 volumio volumio[3927]: info: MPD running with PID4154 Feb 25 03:46:54 volumio volumio[3927]: ,establishing connection Feb 25 03:46:55 volumio volumio[3927]: error: updateQueue error: null Feb 25 03:46:55 volumio volumio[3927]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 03:46:55 volumio volumio[3927]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:46:55 volumio volumio[3927]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:46:55 volumio volumio[3927]: info: CoreCommandRouter::volumioGetState Feb 25 03:46:55 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:55 volumio volumio[3927]: info: CoreStateMachine::pushState Feb 25 03:46:55 volumio volumio[3927]: info: CorePlayQueue::getTrack 0 Feb 25 03:46:55 volumio volumio[3927]: info: CoreCommandRouter::volumioPushState Feb 25 03:46:55 volumio volumio[3927]: info: Completed starting Core Plugins Feb 25 03:46:55 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:55 volumio volumio[3927]: info: ----- MyVolumio plugins startup ---- Feb 25 03:46:55 volumio volumio[3927]: info: ------------------------------------------- Feb 25 03:46:55 volumio volumio[3927]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 03:46:55 volumio volumio[3927]: info: go-librespot daemon successfully initialized Feb 25 03:46:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 25 03:46:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:46:56 volumio go-librespot[4248]: go-librespot daemon starting... Feb 25 03:46:56 volumio go-librespot[4249]: time="2026-02-25T03:46:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:46:56 volumio go-librespot[4249]: time="2026-02-25T03:46:56+07:00" level=debug msg="app state loaded" Feb 25 03:46:56 volumio go-librespot[4249]: time="2026-02-25T03:46:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=info msg="zeroconf server listening on port 42879" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=debug msg="obtained new client token: AAAwa6kTM93oPspG44EAi07TIR9x9bLKkh59BESwJ6KkYakfV5IkpKCULvn5f47Ql5+HU56rNINgTbc11RDaIeCNEURH9NRBBwHEaVopCPw+A3gUMDhsn2mP1peZ/pR0PBkL+82e9ExoxBWVPlQc/dLbXXYbo7e/vI9/T5ZcP/XK6A8NY1RiNVLk1Y/ys8a2q+X8iBT4t4tUFyYnbj2g1bUp6AFAB6pHDpsCD20STaoOE/5WCH/kQDzZug==" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=debug msg="completed keyexchange" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=debug msg="completed challenge" Feb 25 03:46:57 volumio go-librespot[4249]: time="2026-02-25T03:46:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:46:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:46:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:46:58 volumio volumio[3927]: info: Initializing connection to go-librespot Websocket Feb 25 03:46:58 volumio volumio[3927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:46:59 volumio volumio[3927]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 03:47:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 25 03:47:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:00 volumio go-librespot[4256]: go-librespot daemon starting... Feb 25 03:47:00 volumio go-librespot[4257]: time="2026-02-25T03:47:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:00 volumio go-librespot[4257]: time="2026-02-25T03:47:00+07:00" level=debug msg="app state loaded" Feb 25 03:47:00 volumio go-librespot[4257]: time="2026-02-25T03:47:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=info msg="zeroconf server listening on port 33585" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="obtained new client token: AACOn0P2/ffX6WhhX9QJT51v5zZyc+vhp4iTmgMWNNGALx4S8ILgUfwNOg8iih4Z1EPXbcSyLpaIeZOm4yTI8gACmYM4nQAK/PVrPgjGOqg+WNUj/rxNtG2Z+o2riZJw+zsoUj5oVn7Csu/zHt30D+w56wGZaIG1ohbueaVTGVKsiZ1FE8rlTpwuOdp9OTPXmhkUScExRvyteOfQHQBbWGjUQlOPudc7J3Ji9BI7atURTV9tYcme92s/MA==" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="completed challenge" Feb 25 03:47:01 volumio volumio[3927]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:01 volumio go-librespot[4257]: time="2026-02-25T03:47:01+07:00" level=debug msg="new websocket client" Feb 25 03:47:01 volumio volumio[3927]: info: Connection to go-librespot Websocket established Feb 25 03:47:02 volumio go-librespot[4257]: time="2026-02-25T03:47:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:02 volumio volumio[3927]: info: Connection to go-librespot Websocket closed Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 03:47:04 volumio volumio[3927]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 03:47:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 25 03:47:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:05 volumio go-librespot[4281]: go-librespot daemon starting... Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=debug msg="app state loaded" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:05 volumio go-librespot[4282]: time="2026-02-25T03:47:05+07:00" level=info msg="zeroconf server listening on port 40341" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="obtained new client token: AAAQLBIb7FfEXhd1WLzu/6IKc9zbAi3D718M7YHjbMn5pr8TM0pvJjmizQaPsqTlRUYDAXZcMS34IokU4qybUJGb1oOloYcVLWORPTbqPItXN1g5zYq8Am5b8IfOFVmJfGIdSYJbzoukBQ9bVA7383wKrzNmjhAAc17VdGOvkf3TN6USJreUGDzDxVi7bEPhfA+33uQOwpEzwqG7ir71/HZpg+1fXqAcm2ZquSwZuf0nfVqFBk0uZennlg==" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=debug msg="completed challenge" Feb 25 03:47:06 volumio go-librespot[4282]: time="2026-02-25T03:47:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 03:47:06 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:06 volumio volumio[3927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:06 volumio volumio[3927]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 03:47:06 volumio volumio[3927]: info: MyVolumio login type: Token Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 03:47:06 volumio volumio[3927]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 03:47:08 volumio volumio[3927]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 03:47:08 volumio volumio[3927]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 03:47:08 volumio volumio[3927]: info: Streaming services startup Feb 25 03:47:08 volumio volumio[3927]: info: Starting Streaming Daemon Feb 25 03:47:08 volumio sudo[4292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 03:47:08 volumio sudo[4292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:08 volumio volumio[3927]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 03:47:08 volumio sudo[4292]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:08 volumio volumio[3927]: info: Getting Spotify volume Feb 25 03:47:08 volumio volumio[3927]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:08 volumio volumio[3927]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:08 volumio volumio[3927]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:47:08 volumio volumio[3927]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 03:47:08 volumio volumio[3927]: errno: -111, Feb 25 03:47:08 volumio volumio[3927]: code: 'ECONNREFUSED', Feb 25 03:47:08 volumio volumio[3927]: syscall: 'connect', Feb 25 03:47:08 volumio volumio[3927]: address: '127.0.0.1', Feb 25 03:47:08 volumio volumio[3927]: port: 9879, Feb 25 03:47:08 volumio volumio[3927]: response: undefined Feb 25 03:47:08 volumio volumio[3927]: } Feb 25 03:47:08 volumio volumio[3927]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 25 03:47:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:09 volumio go-librespot[4310]: go-librespot daemon starting... Feb 25 03:47:09 volumio go-librespot[4311]: time="2026-02-25T03:47:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:09 volumio go-librespot[4311]: time="2026-02-25T03:47:09+07:00" level=debug msg="app state loaded" Feb 25 03:47:09 volumio go-librespot[4311]: time="2026-02-25T03:47:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:10 volumio sudo[4320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 03:46' Feb 25 03:47:10 volumio sudo[4320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=info msg="zeroconf server listening on port 46263" Feb 25 03:47:10 volumio sudo[4320]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="obtained new client token: AADGKMqkeRyUIiS3l+jFsdGXshQSapy4VkQFTGQ09+2EI+RO/+17HGfGlTO33arGkSayNEyDdyzBaDirHxdBCA1CdzTTaUWWhUL6uf9NiAfsAFNvjxbvFkQI0LHiHQQ6WLdgdBzyafsDGOu0F0JZTbDFyMAF4BFhZDTmOs+apXwAfJzbtQBCndEs90uevsfNFDJmOtvc8YdguxqQzJ/oHwRz59a5CQAqZ5+amuYEDV9jDh5W7ZncewXynQ==" Feb 25 03:47:10 volumio volumio-remote-updater[647]: [2026-02-25 03:47:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 25 03:47:10 volumio volumio-remote-updater[647]: [2026-02-25 03:47:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 25 03:47:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 25 03:47:10 volumio systemd[1]: volumio.service: Consumed 54.054s CPU time. Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:47:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=debug msg="completed challenge" Feb 25 03:47:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7501. Feb 25 03:47:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 03:47:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 25 03:47:10 volumio systemd[1]: volumio.service: Consumed 54.054s CPU time. Feb 25 03:47:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 25 03:47:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 03:47:10 volumio go-librespot[4311]: time="2026-02-25T03:47:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 25 03:47:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:14 volumio go-librespot[4349]: go-librespot daemon starting... Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=debug msg="app state loaded" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:14 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:14 volumio volumio[4333]: info: ----- Volumio3 ---- Feb 25 03:47:14 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:14 volumio volumio[4333]: info: ----- System startup ---- Feb 25 03:47:14 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:14 volumio go-librespot[4350]: time="2026-02-25T03:47:14+07:00" level=info msg="zeroconf server listening on port 44469" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="obtained new client token: AAABhRDk6lKn8dU/715o7IJwA1+ht8A3xBQ2eESPTectYW8dM+LUJcdoF+Y/iDLtwdFR13Sn4bekNnTUsQjTtzAsWX4mNVoQHkUmgpnDYAlz1Zqt2IK57o7vY6wXxAcok470juhCwHG71X4GmZcCdHuOMyTe6vbRWxVYay54T83x+JrMhTnqaYrJ9I03ZUlxMrJR0A1cT5iWTLDOQMneDSngdubAQVPPsg7YcErM62SVtObhtqhQjlmSaA==" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=debug msg="completed challenge" Feb 25 03:47:15 volumio go-librespot[4350]: time="2026-02-25T03:47:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:15 volumio volumio-remote-updater[647]: [2026-02-25 03:47:15] [connect] Successful connection Feb 25 03:47:15 volumio volumio[4333]: info: MYVOLUMIO Environment detected Feb 25 03:47:16 volumio volumio[4333]: info: Plugin folders cleanup Feb 25 03:47:16 volumio volumio[4333]: info: Scanning into folder /volumio/app/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category audio_interface Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category miscellanea Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category music_service Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category plugins.json Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category system_controller Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category user_interface Feb 25 03:47:16 volumio volumio[4333]: info: Scanning into folder /data/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Scanning category music_service Feb 25 03:47:16 volumio volumio[4333]: info: Plugin folders cleanup completed Feb 25 03:47:16 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:16 volumio volumio[4333]: info: ----- Core plugins startup ---- Feb 25 03:47:16 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugins from folder /volumio/app/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Adding plugin upnp to MyMusic Plugins Feb 25 03:47:16 volumio volumio[4333]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 25 03:47:16 volumio volumio[4333]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugins from folder /data/plugins/ Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugin "system"... Feb 25 03:47:16 volumio volumio[4333]: info: Loading plugin "appearance"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "network"... Feb 25 03:47:18 volumio volumio[4333]: info: Refreshing Cached IP Addresses Feb 25 03:47:18 volumio sudo[4370]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:47:18 volumio sudo[4370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:18 volumio sudo[4372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:47:18 volumio sudo[4372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:18 volumio sudo[4370]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:18 volumio sudo[4372]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "services"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "alsa_controller"... Feb 25 03:47:18 volumio sudo[4380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 03:47:18 volumio sudo[4380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:18 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "wizard"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "networkfs"... Feb 25 03:47:18 volumio volumio[4333]: info: Starting Udev Watcher for removable devices Feb 25 03:47:18 volumio volumio[4333]: info: Ignoring mount for partition: boot Feb 25 03:47:18 volumio volumio[4333]: info: Ignoring mount for partition: volumio Feb 25 03:47:18 volumio volumio[4333]: info: Ignoring mount for partition: volumio_data Feb 25 03:47:18 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "volumio_command_line_client"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "upnp"... Feb 25 03:47:18 volumio volumio[4333]: info: [1771966038494] Starting Upmpd Daemon Feb 25 03:47:18 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "my_music"... Feb 25 03:47:18 volumio volumio[4333]: info: Loading plugin "mpd"... Feb 25 03:47:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 25 03:47:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:18 volumio go-librespot[4403]: go-librespot daemon starting... Feb 25 03:47:18 volumio go-librespot[4404]: time="2026-02-25T03:47:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:18 volumio go-librespot[4404]: time="2026-02-25T03:47:18+07:00" level=debug msg="app state loaded" Feb 25 03:47:18 volumio go-librespot[4404]: time="2026-02-25T03:47:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:19 volumio volumio[4333]: info: Loading plugin "upnp_browser"... Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47: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]" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47: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]" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47: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]" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=info msg="zeroconf server listening on port 42253" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="obtained new client token: AACny18JRlM/BuvzY0SS/z39fZRfohurF3NyuYeULVJYwlg26BHweH6ZxEJJGsjA9826IjYU55DUzXDxCwzyjclTe6jSHu44FN3SWs+zKVYNXOMOIVoalMIjwceTUH7FzEnoJTnf43koPZu3nMSiqoB0/h1gEaz2m6ad/JlYInHbbkSTcDMaTZrde7FAZfLBRSy9lepyNPtkl6lLAIggwuPvl9Jn/NdrcWOV3u+O+zejY0V3BBDLo8LAOg==" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=debug msg="completed challenge" Feb 25 03:47:19 volumio go-librespot[4404]: time="2026-02-25T03:47:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:20 volumio sudo[4380]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:22 volumio volumio[4333]: info: Starting UPNP Browser Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "alarm-clock"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "airplay_emulation"... Feb 25 03:47:22 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "last_100"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "webradio"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "i2s_dacs"... Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "volumiodiscovery"... Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio volumio[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio node[4333]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio node[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio node[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio node[4333]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 03:47:22 volumio node[4333]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 03:47:22 volumio node[4333]: *** WARNING *** For more information see Feb 25 03:47:22 volumio volumio[4333]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 25 03:47:22 volumio volumio[4333]: info: Discovery: Started advertising with name: Volumio Feb 25 03:47:22 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 03:47:22 volumio volumio[4333]: info: Loading plugin "spop"... Feb 25 03:47:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 25 03:47:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:23 volumio go-librespot[4413]: go-librespot daemon starting... Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=debug msg="app state loaded" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47: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-gew4.spotify.com:80]" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:23 volumio go-librespot[4414]: time="2026-02-25T03:47:23+07:00" level=info msg="zeroconf server listening on port 43301" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="obtained new client token: AACm7gVDAlx7vBXkmiZEUo+CUnCOzphu9+ProjUh3S1EoxA+RS6HReP8jLxHpDNaRmP87JdS0bdj5ZiCgo3zvgU++G9iBeVHPUtF0COe2n2X07i1/DVytADQLwBePF7jO6p4evxHz3FpZENJYK5ueHjNNh/G6wHYWkqYPMNPun8aWdtagKn3p4glYpt10TGBIZ0uEh6bSETSjtsTv5B1334bA1Uy2shiWZ92y8JrFVPXjbCt8N0otaY=" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=debug msg="completed challenge" Feb 25 03:47:24 volumio go-librespot[4414]: time="2026-02-25T03:47:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:24 volumio volumio[4333]: info: Loading plugin "ytcr"... Feb 25 03:47:27 volumio volumio[4333]: info: Loading plugin "ytmusic"... Feb 25 03:47:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 25 03:47:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:27 volumio go-librespot[4421]: go-librespot daemon starting... Feb 25 03:47:27 volumio go-librespot[4422]: time="2026-02-25T03:47:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:27 volumio go-librespot[4422]: time="2026-02-25T03:47:27+07:00" level=debug msg="app state loaded" Feb 25 03:47:27 volumio go-librespot[4422]: time="2026-02-25T03:47:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:28 volumio volumio-remote-updater[647]: [2026-02-25 03:47:28] [connect] Successful connection Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=info msg="zeroconf server listening on port 33269" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="obtained new client token: AABzsASRxVxNNgQeTFCFDDa+AjbXEo3Y5CyWnHIjlZsXlkHd3l91mi0hKGIMPB8oQ2SrdTJ5LF54pXJS4StPmz3oEuLJNfHECbUHcLTVJxUuX16/OAI1TnBnAo8k2jaC2p1ueWTZ9gsQvtiWoaP1+T0X8r5h+Js/4RJ5s6AFlRCh3igCMs/REhBlPU4/8k40CPk0YsV23yAVw99e1e/j5r7lAjp+b9EMDnIpXAf+OyvMwCi7/dMUut9xAA==" Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "outputs"... Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "albumart"... Feb 25 03:47:28 volumio volumio[4333]: info: Plugin example_plugin is not enabled Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "inputs"... Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "updater_comm"... Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=debug msg="completed challenge" Feb 25 03:47:28 volumio go-librespot[4422]: time="2026-02-25T03:47:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:28 volumio volumio[4333]: info: Plugin mpdemulation is not enabled Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "rest_api"... Feb 25 03:47:28 volumio volumio[4333]: info: Loading plugin "websocket"... Feb 25 03:47:29 volumio volumio[4333]: info: Starting Socket.io Server version 1.7.4 Feb 25 03:47:29 volumio volumio[4333]: info: Loading plugin "RoonBridge"... Feb 25 03:47:29 volumio volumio[4333]: info: Applying required configuration parameters for plugin RoonBridge Feb 25 03:47:29 volumio volumio[4333]: info: Loading i18n strings for locale en Feb 25 03:47:29 volumio volumio[4333]: Updating browse sources language Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::initPlayerControls Feb 25 03:47:29 volumio volumio[4443]: Forking 3 albumart workers Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:47:29 volumio volumio[4333]: Express server listening on port 3000 Feb 25 03:47:29 volumio volumio[4333]: [Metrics] WebUI: 16s 454.21ms Feb 25 03:47:29 volumio volumio[4333]: info: CoreStateMachine::resetVolumioState Feb 25 03:47:29 volumio volumio[4333]: info: CoreStateMachine::getcurrentVolume Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:47:30 volumio sudo[4487]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 03:47:30 volumio sudo[4485]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 03:47:30 volumio sudo[4485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:30 volumio sudo[4485]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:30 volumio sudo[4487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:30 volumio sudo[4487]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:30 volumio volumio[4333]: info: Volumio Network Manager: Network status updated: 1 Feb 25 03:47:30 volumio volumio[4333]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:30 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::updateTrackBlock Feb 25 03:47:30 volumio volumio[4333]: info: CorePlayQueue::getTrackBlock Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:47:30 volumio volumio-remote-updater[647]: [2026-02-25 03:47:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771966048 101 Feb 25 03:47:30 volumio volumio[4333]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 25 03:47:30 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:30 volumio volumio[4333]: info: Reloading queue from file Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::setRepeat null single undefined Feb 25 03:47:30 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:30 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:31 volumio volumio[4333]: info: CoreStateMachine::setRandom null Feb 25 03:47:31 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:31 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:31 volumio volumio[4333]: info: Setting Device type: Raspberry PI Feb 25 03:47:31 volumio volumio[4333]: info: Completed loading Core Plugins Feb 25 03:47:31 volumio volumio[4333]: info: Preparing to generate the ALSA configuration file Feb 25 03:47:31 volumio volumio[4333]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:47:31 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:31 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:31 volumio volumio[4333]: info: Asound.conf file unchanged, so no further update is needed Feb 25 03:47:31 volumio volumio[4333]: info: Output device has changed, restarting MPD Feb 25 03:47:31 volumio volumio[4333]: info: Output device has changed, restarting Shairport Sync Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:31 volumio sudo[4505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 03:47:31 volumio sudo[4505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio sudo[4507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:47:31 volumio sudo[4507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio sudo[4507]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:31 volumio sudo[4509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:47:31 volumio sudo[4509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio volumio[4333]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:47:31 volumio volumio[4333]: info: ___________ START PLUGINS ___________ Feb 25 03:47:31 volumio volumio[4333]: info: ControllerMpd::onStart: Initializing MPD Feb 25 03:47:31 volumio volumio[4333]: info: Creating MPD Configuration file Feb 25 03:47:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 03:47:31 volumio sudo[4505]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:31 volumio sudo[4519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 03:47:31 volumio sudo[4519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio sudo[4519]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:31 volumio volumio[4333]: info: [1771966051660] CoreMusicLibrary::Adding element Media Servers Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:31 volumio volumio[4333]: info: UPNP Browser: Client initialized successfully Feb 25 03:47:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:47:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:47:31 volumio systemd[1]: mpd.service: Consumed 6.964s CPU time. Feb 25 03:47:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:47:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:47:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:47:31 volumio sudo[4520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 03:47:31 volumio sudo[4520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:31 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:47:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:47:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 25 03:47:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:31 volumio go-librespot[4529]: go-librespot daemon starting... Feb 25 03:47:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 03:47:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 03:47:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 03:47:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 03:47:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 03:47:32 volumio volumio[4333]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=debug msg="app state loaded" Feb 25 03:47:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:32 volumio volumio[4333]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:32 volumio volumio[4333]: info: [1771966052200] CoreMusicLibrary::Adding element Last_100 Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:32 volumio volumio[4333]: info: [1771966052228] CoreMusicLibrary::Adding element Webradio Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:47:32 volumio volumio[4333]: info: Initializing BBC Radios Feb 25 03:47:32 volumio sudo[4538]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 03:47:32 volumio sudo[4538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 03:47:32 volumio sudo[4538]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:32 volumio volumio[4333]: info: Creating Spotify config file Feb 25 03:47:32 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:32 volumio go-librespot[4530]: time="2026-02-25T03:47:32+07:00" level=info msg="zeroconf server listening on port 41871" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="obtained new client token: AACidc/fbNrIhxap3z/XSAVGxh9wDx4OWrOxxKUoppco2Yk4a6lqlP6WXq2Jdz2JqZBhRZQFH9JC8KVnimTtkgMBS92YVxpXV3/2zYwNwbIdTV1pVyGe4LY/Fa/uoj1sCZKelj0exVcB+d77FkOOOz+Ww47soa8Ikpw3B6GklmYPbqaq5cfSNKI+i5Li+VBQwU+GDs4x9Mza71RdNsFaH6XizgDv8Jo/orXE5NGu6mWbFKFpZ6Atze4=" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=debug msg="completed challenge" Feb 25 03:47:33 volumio go-librespot[4530]: time="2026-02-25T03:47:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:34 volumio volumio[4455]: Starting albumart workers Feb 25 03:47:34 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:34 volumio volumio[4333]: info: [1771966054697] CoreMusicLibrary::Adding element YouTube Music Feb 25 03:47:34 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:34 volumio volumio[4333]: Cannot find translation for source YouTube Music Feb 25 03:47:34 volumio volumio[4333]: info: Volumio Calling Home Feb 25 03:47:34 volumio volumio[4454]: Starting albumart workers Feb 25 03:47:34 volumio sudo[4560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 03:47:34 volumio sudo[4560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:34 volumio volumio[4453]: Starting albumart workers Feb 25 03:47:35 volumio sudo[4560]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: Found device Volumio Feb 25 03:47:36 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:36 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:36 volumio volumio[4333]: info: MPD Permissions set Feb 25 03:47:36 volumio volumio[4333]: info: MPD Permissions set Feb 25 03:47:36 volumio volumio[4333]: info: Upmpdcli Daemon Started Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 03:47:36 volumio volumio[4333]: info: Discovery: Found device Volumio Feb 25 03:47:36 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:36 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:36 volumio volumio[4333]: info: Volumio called home Feb 25 03:47:36 volumio volumio[4333]: info: Spotify config file written Feb 25 03:47:36 volumio sudo[4566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 03:47:36 volumio sudo[4566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 25 03:47:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio go-librespot[4568]: go-librespot daemon starting... Feb 25 03:47:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 03:47:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 03:47:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:36 volumio go-librespot[4575]: go-librespot daemon starting... Feb 25 03:47:36 volumio sudo[4566]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=debug msg="app state loaded" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:37 volumio volumio[4333]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 03:47:37 volumio volumio[4333]: info: No need to fix Spotify hosts Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47: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-gew1.spotify.com:80]" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:47:37 volumio go-librespot[4577]: time="2026-02-25T03:47:37+07:00" level=info msg="zeroconf server listening on port 43369" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="obtained new client token: AAAwsAUTlm1ebCKj7FUtGS4MzZi9SDPjtlwdsTIfd7ZxQkC8X+2XFfY1L8pt6TioHrWIje5h7qZmLqGJkmBq7QhA20hBD0FYhP3+JJ/0t7S/ynE99BWstHBFngwqjyYdnSvDihiJ+Mut0yEqw24MlVgcBuSuopO8OHJ+tJ/coqgn9pXU+JcNblMFK7t2MrHw5YftopynLvLT7sl9QLwpG7nfJxgPorA7mdIXUrQyr2F+GiLN0vqGHc0=" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=debug msg="completed challenge" Feb 25 03:47:38 volumio go-librespot[4577]: time="2026-02-25T03:47:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:38 volumio volumio[4333]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:47:38 volumio volumio[4333]: SPOTIFY: BQD9-EQUI9iYNweNrZ-WRI6z_Gi8d74nrSlg8EBEgjhiu3PyCDhrA-69FI_QecrFSUSYyuZvPTAwYEVkeupimn4BJYe1G47jVO5s_DVuDnzSSvHr3hIUrGv0J1FgWhj5uT9ZgyGsO7uzTS42Zl3Xm5BjQHB0jyEK0s8IW1_MF3s39ibEo1tbOMfxd2pd0xeAi8ePL6JbU9xTUDateEkh_vrwd_Yh8cBM9a2HRCLAl4sTeTVvWcEpVzJ5ckkZV8bXxqeXsehJMCFEAHJcz8MPfcuHohZGS1nRxbowBrbrz_ihVu5ifrKFhgW0 Feb 25 03:47:38 volumio volumio[4333]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 03:47:38 volumio volumio[4333]: info: New Spotify access token = BQD9-EQUI9iYNweNrZ-WRI6z_Gi8d74nrSlg8EBEgjhiu3PyCDhrA-69FI_QecrFSUSYyuZvPTAwYEVkeupimn4BJYe1G47jVO5s_DVuDnzSSvHr3hIUrGv0J1FgWhj5uT9ZgyGsO7uzTS42Zl3Xm5BjQHB0jyEK0s8IW1_MF3s39ibEo1tbOMfxd2pd0xeAi8ePL6JbU9xTUDateEkh_vrwd_Yh8cBM9a2HRCLAl4sTeTVvWcEpVzJ5ckkZV8bXxqeXsehJMCFEAHJcz8MPfcuHohZGS1nRxbowBrbrz_ihVu5ifrKFhgW0 Feb 25 03:47:38 volumio volumio[4333]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 03:47:38 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:38 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:38 volumio volumio[4333]: info: Starting Shairport Sync Feb 25 03:47:38 volumio sudo[4627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:47:38 volumio sudo[4627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:38 volumio sudo[4629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:47:38 volumio sudo[4629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:38 volumio sudo[4631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 03:47:38 volumio sudo[4631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 03:47:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 03:47:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:47:39 volumio systemd[1]: shairport-sync.service: Consumed 2.147s CPU time. Feb 25 03:47:39 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:39 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 03:47:39 volumio sudo[4627]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio sudo[4629]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio sudo[4631]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio volumio[4333]: info: Shairport-Sync Started Feb 25 03:47:39 volumio volumio[4333]: Error adding Membership: Error: addMembership EINVAL Feb 25 03:47:39 volumio volumio[4333]: info: Shairport-Sync Started Feb 25 03:47:39 volumio volumio[4333]: info: Shairport-Sync Started Feb 25 03:47:39 volumio volumio[4333]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 25 03:47:39 volumio volumio[4333]: info: Spotify Successfully logged in Feb 25 03:47:39 volumio volumio[4333]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 03:47:39 volumio volumio[4333]: info: [1771966059666] CoreMusicLibrary::Adding element Spotify Feb 25 03:47:39 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 03:47:39 volumio volumio[4333]: Cannot find translation for source YouTube Music Feb 25 03:47:39 volumio volumio[4333]: Cannot find translation for source Spotify Feb 25 03:47:39 volumio mpd[4556]: 2026-02-25T03:47:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 03:47:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 03:47:39 volumio sudo[4520]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:39 volumio sudo[4509]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:40 volumio volumio[4333]: error: MPD error: The expression evaluated to a falsy value: Feb 25 03:47:40 volumio volumio[4333]: assert.ok(self.idling) Feb 25 03:47:40 volumio volumio[4333]: error: The expression evaluated to a falsy value: Feb 25 03:47:40 volumio volumio[4333]: assert.ok(self.idling) Feb 25 03:47:40 volumio volumio[4333]: error: updateQueue error: null Feb 25 03:47:40 volumio volumio[4333]: info: MPD running with PID4556 Feb 25 03:47:40 volumio volumio[4333]: ,establishing connection Feb 25 03:47:40 volumio volumio[4333]: error: updateQueue error: null Feb 25 03:47:40 volumio volumio[4333]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 03:47:40 volumio volumio[4333]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 03:47:40 volumio volumio[4333]: info: VolumeController:: Volume=100 Mute =false Feb 25 03:47:40 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:40 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:40 volumio volumio[4333]: info: CoreStateMachine::pushState Feb 25 03:47:40 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:40 volumio volumio[4333]: info: CoreCommandRouter::volumioPushState Feb 25 03:47:40 volumio volumio[4333]: info: Completed starting Core Plugins Feb 25 03:47:40 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:40 volumio volumio[4333]: info: ----- MyVolumio plugins startup ---- Feb 25 03:47:40 volumio volumio[4333]: info: ------------------------------------------- Feb 25 03:47:40 volumio volumio[4333]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 03:47:41 volumio volumio[4333]: info: go-librespot daemon successfully initialized Feb 25 03:47:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 03:47:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:41 volumio go-librespot[4657]: go-librespot daemon starting... Feb 25 03:47:41 volumio go-librespot[4658]: time="2026-02-25T03:47:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:41 volumio go-librespot[4658]: time="2026-02-25T03:47:41+07:00" level=debug msg="app state loaded" Feb 25 03:47:41 volumio go-librespot[4658]: time="2026-02-25T03:47:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=info msg="zeroconf server listening on port 40297" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="obtained new client token: AAAucISYXbEm1KW8iPCPeTOfuP1OrnMIbN6O3ol9erUrCgTd9oyt/smmT7wp7DlCEaVywY2X1jyodLmEWEzYgLbjJYOgibsYaA8igOAy2zw0qpf4fJ1993W+qdQLel+tphKjl4+fjpOc0WtEaPAaZcytrjuFZ+5miTc8sMLrM2rPqI0DpdR34GgliidW8ESRVcKsmbanQyignF2nyVknLVvr+MOQ2HmcICelgMcQecOC5LcFgQ8VI/vrKQ==" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=debug msg="completed challenge" Feb 25 03:47:42 volumio go-librespot[4658]: time="2026-02-25T03:47:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:44 volumio volumio[4333]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:44 volumio volumio[4333]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:47:44 volumio volumio[4333]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 03:47:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 03:47:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:45 volumio go-librespot[4666]: go-librespot daemon starting... Feb 25 03:47:45 volumio go-librespot[4667]: time="2026-02-25T03:47:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:45 volumio go-librespot[4667]: time="2026-02-25T03:47:45+07:00" level=debug msg="app state loaded" Feb 25 03:47:45 volumio go-librespot[4667]: time="2026-02-25T03:47:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=info msg="zeroconf server listening on port 35149" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="obtained new client token: AAAghPOt8O/2GY+4GQFHX3cWUfCnohlyssszYeRSLgcDX+UAE7AccQOx7ldUxoO9Q7Xt08cXP5NDwv9ArRi6ht9nXn+FTcDPf0IeJ/f29tnZ7yQT8y1b1UbEi0QYNBkPADSXWM99AtAlLs1iHshyqodO9xxsUxOvllE0LcFCH6HOZtOyhUnO9LPpsDCHgNxzNce2Ip6QaMyiQg4N2GhNNpomqK2F57dNVa7c8+zLkkX3+6hKu3lWDRIgEA==" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:46 volumio go-librespot[4667]: time="2026-02-25T03:47:46+07:00" level=debug msg="completed challenge" Feb 25 03:47:47 volumio go-librespot[4667]: time="2026-02-25T03:47:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:47 volumio volumio[4333]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:47 volumio volumio[4333]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 03:47:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 03:47:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:50 volumio go-librespot[4688]: go-librespot daemon starting... Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="app state loaded" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:50 volumio volumio[4333]: info: Initializing connection to go-librespot Websocket Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="new websocket client" Feb 25 03:47:50 volumio volumio[4333]: info: Connection to go-librespot Websocket established Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 03:47:50 volumio volumio[4333]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:50 volumio go-librespot[4689]: time="2026-02-25T03:47:50+07:00" level=info msg="zeroconf server listening on port 37651" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="obtained new client token: AABA4TpJcZFNb+cKaYp1rJulW/GtqVIq1K30gYMwVXWt2qDqNjOz7HHoE18moZNhQ0Jdyigy64gO0HEWoARFNOtQTjo0YyOUMjuahMGGZObEWbZmaBDJK5Be2MgvMX5ur1UpyCT40BqJAEqiPWccn10UfTGRyZeCP6Yio7Hau1t1CO3g4wWq/2QoRHGJJ+lzuoAorWznx0RkenBJGJyvS4QO0M7368YxMqhCyn+df8v5oxl4QleS7QBOmw==" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=debug msg="completed challenge" Feb 25 03:47:51 volumio go-librespot[4689]: time="2026-02-25T03:47:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 03:47:52 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:52 volumio volumio[4333]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 03:47:52 volumio volumio[4333]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 03:47:52 volumio volumio[4333]: info: MyVolumio login type: Token Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 03:47:52 volumio volumio[4333]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 03:47:54 volumio volumio[4333]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 03:47:54 volumio volumio[4333]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 03:47:54 volumio volumio[4333]: info: Streaming services startup Feb 25 03:47:54 volumio volumio[4333]: info: Starting Streaming Daemon Feb 25 03:47:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 03:47:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:54 volumio volumio[4333]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 03:47:54 volumio sudo[4700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 03:47:54 volumio sudo[4700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 03:47:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 03:47:54 volumio go-librespot[4705]: go-librespot daemon starting... Feb 25 03:47:54 volumio sudo[4700]: pam_unix(sudo:session): session closed for user root Feb 25 03:47:54 volumio go-librespot[4707]: time="2026-02-25T03:47:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 03:47:54 volumio go-librespot[4707]: time="2026-02-25T03:47:54+07:00" level=debug msg="app state loaded" Feb 25 03:47:54 volumio go-librespot[4707]: time="2026-02-25T03:47:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 03:47:54 volumio volumio[4333]: info: Getting Spotify volume Feb 25 03:47:54 volumio volumio[4333]: info: Connection to go-librespot Websocket closed Feb 25 03:47:54 volumio volumio[4333]: error: Cannot start Volumio Streaming Daemon Feb 25 03:47:54 volumio volumio[4333]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 25 03:47:54 volumio volumio[4333]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 25 03:47:54 volumio volumio[4333]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 25 03:47:55 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:55 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:55 volumio volumio[4333]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 03:47:55 volumio volumio[4333]: SPOTIFY: SPOTIFY VOLUME undefined Feb 25 03:47:55 volumio volumio[4333]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 03:47:55 volumio volumio[4333]: info: Aligning Spotify Volume to Volumio Volume Feb 25 03:47:55 volumio volumio[4333]: info: CoreCommandRouter::volumioGetState Feb 25 03:47:55 volumio volumio[4333]: info: CorePlayQueue::getTrack 0 Feb 25 03:47:55 volumio volumio[4333]: info: Setting Spotify Volume from Volumio: 100 Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=info msg="zeroconf server listening on port 40597" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="obtained new client token: AADP85DI1WZfAOqZ4kL2LyHPFnkSkmt7XJcdRAeBhVQ5kvGRI39tDYLJYeNXsKXtSVSvYzWagQYZabgYX+1LOBZwGPJUOWQantG9iz/D7BrUw1W2nLgHLpTvJxAqZvNKQqLD1HLavgkBD4Bq+ThQxw8g9pXKqtuInjI3fPXvJeMhGDA3yTIUJtc0nPq9yTCEE6iYwbaIb9L1Swnr/99XVnjSBvcTQHhyq5LyeDNJ8KdA+mnR7BtxOh7nlw==" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="completed keyexchange" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=debug msg="completed challenge" Feb 25 03:47:55 volumio go-librespot[4707]: time="2026-02-25T03:47:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 25 03:47:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 03:47:55 volumio volumio[4333]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 03:47:55 volumio volumio[4333]: Error: socket hang up Feb 25 03:47:55 volumio volumio[4333]: at connResetException (node:internal/errors:720:14) Feb 25 03:47:55 volumio volumio[4333]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 25 03:47:55 volumio volumio[4333]: at Socket.emit (node:events:526:35) Feb 25 03:47:55 volumio volumio[4333]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 25 03:47:55 volumio volumio[4333]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 25 03:47:55 volumio volumio[4333]: code: 'ECONNRESET', Feb 25 03:47:55 volumio volumio[4333]: response: undefined Feb 25 03:47:55 volumio volumio[4333]: } Feb 25 03:47:55 volumio volumio[4333]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 03:47:57 volumio sudo[4729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 03:46' Feb 25 03:47:57 volumio sudo[4729]: 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"