Feb 11 00:18:00 volumio volumio[27995]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 00:18:00 volumio volumio[27995]: info: Discovery: Found device Volumio Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:00 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:00 volumio volumio[27995]: info: MPD Permissions set Feb 11 00:18:00 volumio volumio[27995]: info: MPD Permissions set Feb 11 00:18:00 volumio volumio[27995]: info: Upmpdcli Daemon Started Feb 11 00:18:00 volumio volumio[27995]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 00:18:00 volumio volumio[27995]: info: Discovery: Found device Volumio Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:00 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:00 volumio volumio[27995]: info: Spotify config file written Feb 11 00:18:00 volumio sudo[28231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 00:18:00 volumio sudo[28231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:00 volumio volumio[27995]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 00:18:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 00:18:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:00 volumio go-librespot[28236]: go-librespot daemon starting... Feb 11 00:18:00 volumio sudo[28231]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:00 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:00 volumio go-librespot[28244]: time="2026-02-11T00:18:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:00 volumio go-librespot[28244]: time="2026-02-11T00:18:00+07:00" level=debug msg="app state loaded" Feb 11 00:18:00 volumio go-librespot[28244]: time="2026-02-11T00:18:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:00 volumio volumio[27995]: info: No need to fix Spotify hosts Feb 11 00:18:01 volumio go-librespot[28244]: time="2026-02-11T00:18: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 00:18:01 volumio go-librespot[28244]: time="2026-02-11T00:18:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 00:18:01 volumio go-librespot[28244]: time="2026-02-11T00:18:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 00:18:01 volumio go-librespot[28244]: time="2026-02-11T00:18:01+07:00" level=info msg="zeroconf server listening on port 36885" Feb 11 00:18:01 volumio volumio[27995]: info: Volumio called home Feb 11 00:18:01 volumio go-librespot[28244]: time="2026-02-11T00:18:01+07:00" level=debug msg="obtained new client token: AACohgcepXDYu87xNBguM3hS+VPeAqYLJytFTr/o29yLqHNMKS1AEhHfNY/4nR87uqdqgZ9BPV1l0+L219DvUAJ1hnTN7Aalx4EtWnPzQYCA/NAVm1EqJFYbbpoeL2rLroQuOgCqIM/z1VNN+JB/CQnJu+H/zs/nGlUsHFvB/dvL9fPTW4ASI9nMHA4uG86Ejcu7rqWSdBgCbyTR+9Ke5jEwUUnlF367znp98MlLC+1WLHjC7H+wkbBvEA==" Feb 11 00:18:02 volumio go-librespot[28244]: time="2026-02-11T00:18:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:02 volumio go-librespot[28244]: time="2026-02-11T00:18:02+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:02 volumio go-librespot[28244]: time="2026-02-11T00:18:02+07:00" level=debug msg="completed challenge" Feb 11 00:18:02 volumio go-librespot[28244]: time="2026-02-11T00:18: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 11 00:18:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:02 volumio volumio[27995]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 00:18:02 volumio volumio[27995]: SPOTIFY: BQAzVpIBvvD6OYhetVWSrumrk6NOsiEuU-1EI8olygX8K8mqXuOXoh38j1SPcZ7evIddXUIRWUulrGQY9Ly27qoLd6yClah8dYIXOLI39b--kAp_Q6yGmZwEFKIGt9k_TU9KNkZdiymi9qpv_oCol3v9eJSkYSCKXkuDvTm5fVrBvVOxXzFMCkIXpNgMoqpC4Do4M2KVeVDPtvAxFv7Hk3VPmglj95tW-vIDuzYg-TSe7HpACp6pygs9_gXB9GQkZpiakKtdTZpfRSgl-NLgUeevBn1GqqgQE1k_JTybn4zF0YTPbg3t9KDf Feb 11 00:18:02 volumio volumio[27995]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 00:18:02 volumio volumio[27995]: info: New Spotify access token = BQAzVpIBvvD6OYhetVWSrumrk6NOsiEuU-1EI8olygX8K8mqXuOXoh38j1SPcZ7evIddXUIRWUulrGQY9Ly27qoLd6yClah8dYIXOLI39b--kAp_Q6yGmZwEFKIGt9k_TU9KNkZdiymi9qpv_oCol3v9eJSkYSCKXkuDvTm5fVrBvVOxXzFMCkIXpNgMoqpC4Do4M2KVeVDPtvAxFv7Hk3VPmglj95tW-vIDuzYg-TSe7HpACp6pygs9_gXB9GQkZpiakKtdTZpfRSgl-NLgUeevBn1GqqgQE1k_JTybn4zF0YTPbg3t9KDf Feb 11 00:18:02 volumio volumio[27995]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 00:18:02 volumio volumio[27995]: info: Starting Shairport Sync Feb 11 00:18:02 volumio volumio[27995]: info: Starting Shairport Sync Feb 11 00:18:02 volumio volumio[27995]: info: Starting Shairport Sync Feb 11 00:18:02 volumio sudo[28272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:18:02 volumio sudo[28272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:02 volumio sudo[28274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:18:02 volumio sudo[28274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 00:18:02 volumio sudo[28276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:18:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 00:18:02 volumio sudo[28276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:02 volumio systemd[1]: shairport-sync.service: Consumed 2.304s CPU time. Feb 11 00:18:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:02 volumio sudo[28272]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:02 volumio volumio[27995]: info: Shairport-Sync Started Feb 11 00:18:02 volumio volumio[27995]: Error adding Membership: Error: addMembership EINVAL Feb 11 00:18:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 00:18:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 00:18:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:02 volumio volumio[27995]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:02 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:03 volumio sudo[28276]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:03 volumio sudo[28274]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:03 volumio volumio[27995]: info: Shairport-Sync Started Feb 11 00:18:03 volumio volumio[27995]: info: Shairport-Sync Started Feb 11 00:18:03 volumio volumio[27995]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 11 00:18:03 volumio volumio[27995]: info: Spotify Successfully logged in Feb 11 00:18:03 volumio volumio[27995]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:18:03 volumio volumio[27995]: info: [1770743883116] CoreMusicLibrary::Adding element Spotify Feb 11 00:18:03 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:03 volumio volumio[27995]: Cannot find translation for source YouTube Music Feb 11 00:18:03 volumio volumio[27995]: Cannot find translation for source Spotify Feb 11 00:18:03 volumio volumio[27995]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 00:18:03 volumio volumio[27995]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:18:04 volumio volumio[27995]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:18:04 volumio volumio[27995]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:04 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:04 volumio volumio[27995]: info: CoreStateMachine::pushState Feb 11 00:18:04 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:04 volumio volumio[27995]: info: CoreCommandRouter::volumioPushState Feb 11 00:18:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 00:18:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:05 volumio volumio[27995]: info: go-librespot daemon successfully initialized Feb 11 00:18:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:05 volumio go-librespot[28312]: go-librespot daemon starting... Feb 11 00:18:05 volumio go-librespot[28313]: time="2026-02-11T00:18:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:05 volumio go-librespot[28313]: time="2026-02-11T00:18:05+07:00" level=debug msg="app state loaded" Feb 11 00:18:05 volumio go-librespot[28313]: time="2026-02-11T00:18:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:05 volumio mpd[28212]: 2026-02-11T00:18:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 00:18:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 00:18:05 volumio sudo[28183]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:05 volumio sudo[28172]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:05 volumio volumio[27995]: error: MPD error: The expression evaluated to a falsy value: Feb 11 00:18:05 volumio volumio[27995]: assert.ok(self.idling) Feb 11 00:18:05 volumio volumio[27995]: error: The expression evaluated to a falsy value: Feb 11 00:18:05 volumio volumio[27995]: assert.ok(self.idling) Feb 11 00:18:05 volumio volumio[27995]: error: updateQueue error: null Feb 11 00:18:05 volumio volumio[27995]: info: MPD running with PID28212 Feb 11 00:18:05 volumio volumio[27995]: ,establishing connection Feb 11 00:18:05 volumio volumio[27995]: info: Completed starting Core Plugins Feb 11 00:18:05 volumio volumio[27995]: info: ------------------------------------------- Feb 11 00:18:05 volumio volumio[27995]: info: ----- MyVolumio plugins startup ---- Feb 11 00:18:05 volumio volumio[27995]: info: ------------------------------------------- Feb 11 00:18:05 volumio volumio[27995]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 00:18:05 volumio volumio[27995]: error: updateQueue error: null Feb 11 00:18:05 volumio go-librespot[28313]: time="2026-02-11T00:18:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 00:18:05 volumio go-librespot[28313]: time="2026-02-11T00:18:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 00:18:05 volumio go-librespot[28313]: time="2026-02-11T00:18:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 00:18:06 volumio go-librespot[28313]: time="2026-02-11T00:18:06+07:00" level=info msg="zeroconf server listening on port 33333" Feb 11 00:18:06 volumio go-librespot[28313]: time="2026-02-11T00:18:06+07:00" level=debug msg="obtained new client token: AABzHIMLPVX9VGgjpM3N1d9xVJhgL7gX+UXl8mwPf8//nxzntwdUT5dVD46/cP4WZkSlMGTQWABPmp73eDcUKC4SWag7GmFfbHegr02cDoWFwsrAyEuEZbGOsw2rzjDGkJQpD8vqneG/YbxgrZZBbCZlcMJtiC+GbL4cqIn+EXYgGuy73We1JBbSapw5JEIHQhmNx4z2J4YeEIGJ9lsvORzWnJjIkGL2sWc/HTuEVFbCqwWL3CwOejU=" Feb 11 00:18:06 volumio go-librespot[28313]: time="2026-02-11T00:18:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:06 volumio go-librespot[28313]: time="2026-02-11T00:18:06+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:06 volumio go-librespot[28313]: time="2026-02-11T00:18:06+07:00" level=debug msg="completed challenge" Feb 11 00:18:06 volumio go-librespot[28313]: time="2026-02-11T00:18: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 11 00:18:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:08 volumio volumio[27995]: info: Initializing connection to go-librespot Websocket Feb 11 00:18:08 volumio volumio[27995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 00:18:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 00:18:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:09 volumio go-librespot[28325]: go-librespot daemon starting... Feb 11 00:18:09 volumio go-librespot[28326]: time="2026-02-11T00:18:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:09 volumio go-librespot[28326]: time="2026-02-11T00:18:09+07:00" level=debug msg="app state loaded" Feb 11 00:18:09 volumio go-librespot[28326]: time="2026-02-11T00:18:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18: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 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18: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 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18: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 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18:10+07:00" level=info msg="zeroconf server listening on port 44285" Feb 11 00:18:10 volumio volumio[27995]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18:10+07:00" level=debug msg="obtained new client token: AABr5Mh/rp7iUHDsy8crGmVW+zjGcQSIXIqehP0hPDdePPkhQJt8de7VYELbA5dKP8HkyA7FRx838JThq1iId/gd6RJo8NbcFU1arqspwEdNkpPvHU/TZPmCVaBe4eImhYaGZIovWM1Ys0+q+2+rJCb9wKU0uMr4g48lCxFPJXVcSgRKhPCow1dxYPr+DsNtFDtwhkFt7iPdPNDF+TcNfG0MehSzlDgxPBPM3EwFx2uBtd3BmIRH60Atng==" Feb 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18:10+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:10 volumio go-librespot[28326]: time="2026-02-11T00:18:10+07:00" level=debug msg="completed challenge" Feb 11 00:18:11 volumio go-librespot[28326]: time="2026-02-11T00:18:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:11 volumio volumio[27995]: info: Initializing connection to go-librespot Websocket Feb 11 00:18:11 volumio volumio[27995]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 00:18:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 00:18:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:14 volumio go-librespot[28333]: go-librespot daemon starting... Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=debug msg="app state loaded" Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:14 volumio volumio[27995]: info: Initializing connection to go-librespot Websocket Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=debug msg="new websocket client" Feb 11 00:18:14 volumio volumio[27995]: info: Connection to go-librespot Websocket established Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=info msg="zeroconf server listening on port 36479" Feb 11 00:18:14 volumio go-librespot[28334]: time="2026-02-11T00:18:14+07:00" level=debug msg="obtained new client token: AABs4MkMzCFLSmuhc+bUYYsbKxGDFxq5AhULpV6lnoOrwoeXVZrWFRcNdfS74qkETJocaYy/xO23iJOgl0OcFyvfqFwQv3ij7FIk64EOrHMO8Z8kIKHO3pQeW/PAw0je50upBr9QWYAq06MHJUdzfhcb4420XHvl7YdPPnWskBV82vyWQvwQkHFxuGsqxyeQhgIglmsUR7lpnHbcvu8GrRSjlfB/5h8Y1wQeJPnwKt9lebZQe/zKcgLDpg==" Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 00:18:15 volumio go-librespot[28334]: time="2026-02-11T00:18:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 00:18:15 volumio volumio[27995]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 00:18:15 volumio volumio[27995]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 00:18:15 volumio go-librespot[28334]: time="2026-02-11T00:18:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:42254->104.199.241.202:4070: read: connection reset by peer" Feb 11 00:18:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:16 volumio volumio[27995]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 00:18:16 volumio volumio[27995]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 00:18:16 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:16 volumio volumio[27995]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:16 volumio volumio[27995]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 00:18:16 volumio volumio[27995]: info: MyVolumio login type: Token Feb 11 00:18:17 volumio volumio[27995]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 00:18:17 volumio volumio[27995]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 00:18:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 00:18:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:18 volumio go-librespot[28356]: go-librespot daemon starting... Feb 11 00:18:18 volumio go-librespot[28357]: time="2026-02-11T00:18:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:18 volumio go-librespot[28357]: time="2026-02-11T00:18:18+07:00" level=debug msg="app state loaded" Feb 11 00:18:18 volumio go-librespot[28357]: time="2026-02-11T00:18:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:18 volumio volumio[27995]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 00:18:18 volumio volumio[27995]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 00:18:18 volumio volumio[27995]: info: Streaming services startup Feb 11 00:18:18 volumio volumio[27995]: info: Starting Streaming Daemon Feb 11 00:18:18 volumio sudo[28366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 00:18:18 volumio sudo[28366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:18 volumio volumio[27995]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 00:18:18 volumio sudo[28366]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18: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 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18: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 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18: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 11 00:18:19 volumio volumio[27995]: info: Getting Spotify volume Feb 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18:19+07:00" level=info msg="zeroconf server listening on port 38067" Feb 11 00:18:19 volumio volumio[27995]: info: Connection to go-librespot Websocket closed Feb 11 00:18:19 volumio volumio[27995]: error: Cannot start Volumio Streaming Daemon Feb 11 00:18:19 volumio volumio[27995]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 00:18:19 volumio volumio[27995]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 00:18:19 volumio volumio[27995]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18:19+07:00" level=debug msg="obtained new client token: AACiEywcgm4qWZLhARKsAtfBw76+rJOPMcPIhcQQz/ZxoCpUjrl/n/sY+lkOvGkC8j8ImKmde8+H40jekkIpIav3BlunL6/hR9p8qTD5lsSwOGNCK0kXrdUaGaZp1s7fyGrhUN0KqFxFIEUxd2TEFN0v4BVwVdu6hppAbmY4YE5e9tJ/d6qubDJOprYsRN2ejpIRYM0EpLBktLjVyJPJP5dbAumgfPd/vMdKHvOWJSc3zlqgEWnxeLU=" Feb 11 00:18:19 volumio volumio[27995]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:19 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:19 volumio volumio[27995]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 11 00:18:19 volumio volumio[27995]: SPOTIFY: SPOTIFY VOLUME undefined Feb 11 00:18:19 volumio volumio[27995]: SPOTIFY: VOLUMIO VOLUME 100 Feb 11 00:18:19 volumio volumio[27995]: info: Aligning Spotify Volume to Volumio Volume Feb 11 00:18:19 volumio volumio[27995]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:19 volumio volumio[27995]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:19 volumio volumio[27995]: info: Setting Spotify Volume from Volumio: 100 Feb 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:19 volumio go-librespot[28357]: time="2026-02-11T00:18:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:18:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:19 volumio volumio[27995]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 00:18:19 volumio volumio[27995]: Error: socket hang up Feb 11 00:18:19 volumio volumio[27995]: at connResetException (node:internal/errors:720:14) Feb 11 00:18:19 volumio volumio[27995]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 00:18:19 volumio volumio[27995]: at Socket.emit (node:events:526:35) Feb 11 00:18:19 volumio volumio[27995]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 00:18:19 volumio volumio[27995]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 00:18:19 volumio volumio[27995]: code: 'ECONNRESET', Feb 11 00:18:19 volumio volumio[27995]: response: undefined Feb 11 00:18:19 volumio volumio[27995]: } Feb 11 00:18:19 volumio volumio[27995]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 00:18:20 volumio sudo[28387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 00:17' Feb 11 00:18:20 volumio sudo[28387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:21 volumio sudo[28387]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:21 volumio volumio-remote-updater[643]: [2026-02-11 00:18:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 00:18:21 volumio volumio-remote-updater[643]: [2026-02-11 00:18:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 00:18:21 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:21 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 00:18:21 volumio systemd[1]: volumio.service: Consumed 55.565s CPU time. Feb 11 00:18:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 00:18:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 00:18:21 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10934. Feb 11 00:18:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 00:18:21 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 00:18:21 volumio systemd[1]: volumio.service: Consumed 55.565s CPU time. Feb 11 00:18:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 00:18:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 00:18:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 00:18:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:22 volumio go-librespot[28415]: go-librespot daemon starting... Feb 11 00:18:22 volumio go-librespot[28416]: time="2026-02-11T00:18:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:22 volumio go-librespot[28416]: time="2026-02-11T00:18:22+07:00" level=debug msg="app state loaded" Feb 11 00:18:22 volumio go-librespot[28416]: time="2026-02-11T00:18:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=info msg="zeroconf server listening on port 36195" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="obtained new client token: AAB0vQ6ARQrj5p50zZiqGtE8oNd74osfkFSoXoC/9ijlEJOzIWv3FL/0wn4+xmGzQHGtwO0j3glsgiak2Hb35Phn7dF7IXl3B9buQXZ5JPuOMIv4vCvTHDQ9xtcyq2ooy3Zd6Rl1uly3uxDM1m6fxskRnMicwUQ6dyaQdZ0MDnu3DOX9fsvZBtAzL/7ZCKW7s7aYDQYrdwPBBPWXkkxe7JkxhC8cYdrgkjQ0uM/+JUaigZPxJP6Jw5wObw==" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=debug msg="completed challenge" Feb 11 00:18:23 volumio go-librespot[28416]: time="2026-02-11T00:18:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:25 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:25 volumio volumio[28400]: info: ----- Volumio3 ---- Feb 11 00:18:25 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:25 volumio volumio[28400]: info: ----- System startup ---- Feb 11 00:18:25 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:26 volumio volumio-remote-updater[643]: [2026-02-11 00:18:26] [connect] Successful connection Feb 11 00:18:26 volumio volumio[28400]: info: MYVOLUMIO Environment detected Feb 11 00:18:26 volumio volumio[28400]: info: Plugin folders cleanup Feb 11 00:18:26 volumio volumio[28400]: info: Scanning into folder /volumio/app/plugins/ Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category audio_interface Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category miscellanea Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category music_service Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category plugins.json Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category system_controller Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category user_interface Feb 11 00:18:26 volumio volumio[28400]: info: Scanning into folder /data/plugins/ Feb 11 00:18:26 volumio volumio[28400]: info: Scanning category music_service Feb 11 00:18:26 volumio volumio[28400]: info: Plugin folders cleanup completed Feb 11 00:18:26 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:26 volumio volumio[28400]: info: ----- Core plugins startup ---- Feb 11 00:18:26 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:26 volumio volumio[28400]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 00:18:26 volumio volumio[28400]: info: Adding plugin upnp to MyMusic Plugins Feb 11 00:18:26 volumio volumio[28400]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 00:18:26 volumio volumio[28400]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 00:18:26 volumio volumio[28400]: info: Loading plugins from folder /data/plugins/ Feb 11 00:18:26 volumio volumio[28400]: info: Loading plugin "system"... Feb 11 00:18:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 00:18:26 volumio volumio[28400]: info: Loading plugin "appearance"... Feb 11 00:18:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:26 volumio go-librespot[28436]: go-librespot daemon starting... Feb 11 00:18:26 volumio go-librespot[28437]: time="2026-02-11T00:18:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:26 volumio go-librespot[28437]: time="2026-02-11T00:18:26+07:00" level=debug msg="app state loaded" Feb 11 00:18:26 volumio go-librespot[28437]: time="2026-02-11T00:18:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=info msg="zeroconf server listening on port 38779" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="obtained new client token: AADZwctG45QC4wLnzLw8x/RJDWOK+PV0f61lFkEHtwGRWdwHT97Dq2vUXow+2a6yLOKDGzqFoVdsgcH0gVmmr0d9B0e2EuvExhTeNi6F4JgSPAa+OF0/70lmsSiFloHJ/sbM8isj7+oCE5xdBc+V5xrrx+j7mcBbmvQcK2TwpqPsJH+v4XsxKQh2lI8dRAl3Um0TkzyefVohT7ev4EHlXD2BQNbwLNBMfVf50eNMsEnYb6sVNoLZIDzdZg==" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:27 volumio go-librespot[28437]: time="2026-02-11T00:18:27+07:00" level=debug msg="completed challenge" Feb 11 00:18:28 volumio go-librespot[28437]: time="2026-02-11T00:18:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:28 volumio volumio[28400]: info: Loading plugin "network"... Feb 11 00:18:28 volumio volumio[28400]: info: Refreshing Cached IP Addresses Feb 11 00:18:28 volumio sudo[28446]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 00:18:28 volumio sudo[28446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:28 volumio volumio[28400]: info: Loading plugin "services"... Feb 11 00:18:28 volumio sudo[28448]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 00:18:28 volumio sudo[28448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:28 volumio sudo[28446]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:28 volumio volumio[28400]: info: Loading plugin "alsa_controller"... Feb 11 00:18:28 volumio sudo[28448]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:28 volumio sudo[28459]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 00:18:28 volumio sudo[28459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:29 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "wizard"... Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "networkfs"... Feb 11 00:18:29 volumio volumio[28400]: info: Starting Udev Watcher for removable devices Feb 11 00:18:29 volumio volumio[28400]: info: Ignoring mount for partition: boot Feb 11 00:18:29 volumio volumio[28400]: info: Ignoring mount for partition: volumio Feb 11 00:18:29 volumio volumio[28400]: info: Ignoring mount for partition: volumio_data Feb 11 00:18:29 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "volumio_command_line_client"... Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "upnp"... Feb 11 00:18:29 volumio volumio[28400]: info: [1770743909187] Starting Upmpd Daemon Feb 11 00:18:29 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "my_music"... Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "mpd"... Feb 11 00:18:29 volumio volumio[28400]: info: Loading plugin "upnp_browser"... Feb 11 00:18:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 00:18:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:31 volumio go-librespot[28479]: go-librespot daemon starting... Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=debug msg="app state loaded" Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:31 volumio sudo[28459]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=info msg="zeroconf server listening on port 34703" Feb 11 00:18:31 volumio go-librespot[28480]: time="2026-02-11T00:18:31+07:00" level=debug msg="obtained new client token: AAAqxD1NFp3fUQJKyUQ+DGOO1CSRYBMcJgSAOWJW/6nGfgNTBkvSoQyE40nlsqRKrwtkelclJ7xw/Bij8WPhZnfpcraR4929hjDZQxbHxN5Fq1kg9gMepXIv4l/HaHv30wMycQwcGzyIRMCOrjya2RJNGTmVbk+7gCNob+pF0PJfkAiT1CvHXsIlJLSBlWSoLeJ/rFVd+K/q2kn9XZlhIMoEGtA9qSr9FKPDhD70pT1XdPhZ4bXyWhJkEA==" Feb 11 00:18:32 volumio go-librespot[28480]: time="2026-02-11T00:18:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:32 volumio go-librespot[28480]: time="2026-02-11T00:18:32+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:32 volumio go-librespot[28480]: time="2026-02-11T00:18:32+07:00" level=debug msg="completed challenge" Feb 11 00:18:32 volumio go-librespot[28480]: time="2026-02-11T00:18:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:32 volumio volumio[28400]: info: Starting UPNP Browser Feb 11 00:18:32 volumio volumio[28400]: info: Loading plugin "alarm-clock"... Feb 11 00:18:33 volumio volumio[28400]: info: Loading plugin "airplay_emulation"... Feb 11 00:18:33 volumio volumio[28400]: info: Starting Shairport Sync Feb 11 00:18:33 volumio volumio[28400]: info: Loading plugin "last_100"... Feb 11 00:18:33 volumio volumio[28400]: info: Loading plugin "webradio"... Feb 11 00:18:33 volumio volumio[28400]: info: Loading plugin "i2s_dacs"... Feb 11 00:18:33 volumio volumio[28400]: info: Loading plugin "volumiodiscovery"... Feb 11 00:18:33 volumio volumio[28400]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 00:18:33 volumio volumio[28400]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:18:33 volumio node[28400]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 00:18:33 volumio volumio[28400]: *** WARNING *** For more information see Feb 11 00:18:33 volumio volumio[28400]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 00:18:33 volumio volumio[28400]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:18:33 volumio volumio[28400]: *** WARNING *** For more information see Feb 11 00:18:33 volumio node[28400]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:18:33 volumio node[28400]: *** WARNING *** For more information see Feb 11 00:18:33 volumio node[28400]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 00:18:33 volumio node[28400]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:18:33 volumio node[28400]: *** WARNING *** For more information see Feb 11 00:18:33 volumio volumio[28400]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 00:18:33 volumio volumio[28400]: info: Discovery: Started advertising with name: Volumio Feb 11 00:18:33 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 00:18:33 volumio volumio[28400]: info: Loading plugin "spop"... Feb 11 00:18:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 00:18:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:35 volumio volumio[28400]: info: Loading plugin "ytcr"... Feb 11 00:18:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:35 volumio go-librespot[28491]: go-librespot daemon starting... Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=debug msg="app state loaded" Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:35 volumio go-librespot[28492]: time="2026-02-11T00:18:35+07:00" level=info msg="zeroconf server listening on port 33257" Feb 11 00:18:36 volumio go-librespot[28492]: time="2026-02-11T00:18:36+07:00" level=debug msg="obtained new client token: AABvfsJr/RH7fWqz6oHRE+OHgCRjXforLljgNFWqNybwwMAwEh4WOGoAVp1gmUpTMuXJtIi5i0onsQcpq0FWNJ2B/Ey5UuDH/G/mJ3hHlh5r9goEopcBF7Qcckr68DLvnCoKzhBRpiru9OC5rvkhohseArwxgi5L4RhzF0X/8wYjR9mtyMqxNiuEeMivjbXUWro9t3v025rTtjFEYSNGMAHRtrNfG/yCu5V1DS4+036BC7+iogGxedU=" Feb 11 00:18:36 volumio go-librespot[28492]: time="2026-02-11T00:18:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:36 volumio go-librespot[28492]: time="2026-02-11T00:18:36+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:36 volumio go-librespot[28492]: time="2026-02-11T00:18:36+07:00" level=debug msg="completed challenge" Feb 11 00:18:36 volumio go-librespot[28492]: time="2026-02-11T00:18:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:38 volumio volumio[28400]: info: Loading plugin "ytmusic"... Feb 11 00:18:38 volumio volumio-remote-updater[643]: [2026-02-11 00:18:38] [connect] Successful connection Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "outputs"... Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "albumart"... Feb 11 00:18:39 volumio volumio[28400]: info: Plugin example_plugin is not enabled Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "inputs"... Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "updater_comm"... Feb 11 00:18:39 volumio volumio[28400]: info: Plugin mpdemulation is not enabled Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "rest_api"... Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "websocket"... Feb 11 00:18:39 volumio volumio[28400]: info: Starting Socket.io Server version 1.7.4 Feb 11 00:18:39 volumio volumio[28400]: info: Loading plugin "RoonBridge"... Feb 11 00:18:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 00:18:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:39 volumio go-librespot[28524]: go-librespot daemon starting... Feb 11 00:18:39 volumio go-librespot[28525]: time="2026-02-11T00:18:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:39 volumio go-librespot[28525]: time="2026-02-11T00:18:39+07:00" level=debug msg="app state loaded" Feb 11 00:18:39 volumio go-librespot[28525]: time="2026-02-11T00:18:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:40 volumio volumio[28400]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 00:18:40 volumio volumio[28400]: info: Loading i18n strings for locale en Feb 11 00:18:40 volumio volumio[28400]: Updating browse sources language Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:40 volumio go-librespot[28525]: time="2026-02-11T00:18:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:40 volumio go-librespot[28525]: time="2026-02-11T00:18:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:40 volumio go-librespot[28525]: time="2026-02-11T00:18:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:40 volumio volumio[28514]: Forking 3 albumart workers Feb 11 00:18:40 volumio go-librespot[28525]: time="2026-02-11T00:18:40+07:00" level=info msg="zeroconf server listening on port 41411" Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::initPlayerControls Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 00:18:40 volumio volumio[28400]: Express server listening on port 3000 Feb 11 00:18:40 volumio volumio[28400]: [Metrics] WebUI: 16s 104.47ms Feb 11 00:18:40 volumio volumio[28400]: info: CoreStateMachine::resetVolumioState Feb 11 00:18:40 volumio volumio[28400]: info: CoreStateMachine::getcurrentVolume Feb 11 00:18:40 volumio volumio[28400]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:18:40 volumio go-librespot[28525]: time="2026-02-11T00:18:40+07:00" level=debug msg="obtained new client token: AADXqHM2x1tSYc4c1OyuIjY+EINBb6CU/yrHRRK1gzG6Qh5A7OmwoqWRbGj9S0O+KKSNpVsbOneSgKzqz2i/KB/q2Mofm8guC84qlIUufzLwaYPHVsgqFA6O46k9/G4MLVrql/te5SZCf+Dncxk67s+iqJ4NDt04DMNxrtozovmHRev715V7OscP2HhKgiWIabxjyiA+WFh8pxiAJZfpw4EgSRTrmogOtedYdGe493S+F5wx7RdcH1MMvw==" Feb 11 00:18:40 volumio sudo[28564]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 00:18:40 volumio sudo[28564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:40 volumio sudo[28566]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 00:18:40 volumio sudo[28566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:40 volumio go-librespot[28525]: time="2026-02-11T00:18:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:40 volumio sudo[28564]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:40 volumio sudo[28566]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:40 volumio volumio[28400]: info: Volumio Network Manager: Network status updated: 1 Feb 11 00:18:40 volumio volumio[28400]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:18:40 volumio volumio[28400]: info: CoreStateMachine::pushState Feb 11 00:18:40 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::volumioPushState Feb 11 00:18:41 volumio volumio[28400]: info: CoreStateMachine::updateTrackBlock Feb 11 00:18:41 volumio volumio[28400]: info: CorePlayQueue::getTrackBlock Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:18:41 volumio volumio-remote-updater[643]: [2026-02-11 00:18:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770743918 101 Feb 11 00:18:41 volumio volumio[28400]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:41 volumio volumio[28400]: info: Reloading queue from file Feb 11 00:18:41 volumio volumio[28400]: info: CoreStateMachine::setRepeat null single undefined Feb 11 00:18:41 volumio volumio[28400]: info: CoreStateMachine::pushState Feb 11 00:18:41 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::volumioPushState Feb 11 00:18:41 volumio volumio[28400]: info: CoreStateMachine::setRandom null Feb 11 00:18:41 volumio volumio[28400]: info: CoreStateMachine::pushState Feb 11 00:18:41 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::volumioPushState Feb 11 00:18:41 volumio volumio[28400]: info: Setting Device type: Raspberry PI Feb 11 00:18:41 volumio volumio[28400]: info: Completed loading Core Plugins Feb 11 00:18:41 volumio volumio[28400]: info: Preparing to generate the ALSA configuration file Feb 11 00:18:41 volumio volumio[28400]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:18:41 volumio volumio[28400]: info: CoreStateMachine::pushState Feb 11 00:18:41 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::volumioPushState Feb 11 00:18:41 volumio volumio[28400]: info: Asound.conf file unchanged, so no further update is needed Feb 11 00:18:41 volumio volumio[28400]: info: Output device has changed, restarting MPD Feb 11 00:18:41 volumio volumio[28400]: info: Output device has changed, restarting Shairport Sync Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:41 volumio sudo[28583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 00:18:41 volumio sudo[28583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:41 volumio go-librespot[28525]: time="2026-02-11T00:18:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:56696->104.199.241.202:4070: read: connection reset by peer" Feb 11 00:18:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:41 volumio volumio[28400]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 00:18:41 volumio sudo[28585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 00:18:41 volumio volumio[28400]: info: ___________ START PLUGINS ___________ Feb 11 00:18:41 volumio sudo[28585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:41 volumio sudo[28587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 00:18:41 volumio sudo[28585]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:41 volumio volumio[28400]: info: ControllerMpd::onStart: Initializing MPD Feb 11 00:18:41 volumio volumio[28400]: info: Creating MPD Configuration file Feb 11 00:18:41 volumio sudo[28587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:18:41 volumio volumio[28400]: info: [1770743921786] CoreMusicLibrary::Adding element Media Servers Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:41 volumio sudo[28583]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:41 volumio sudo[28596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 00:18:41 volumio volumio[28400]: info: UPNP Browser: Client initialized successfully Feb 11 00:18:41 volumio sudo[28596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 00:18:41 volumio sudo[28596]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:41 volumio sudo[28598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 00:18:41 volumio sudo[28598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:41 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 00:18:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 00:18:42 volumio systemd[1]: mpd.service: Consumed 7.167s CPU time. Feb 11 00:18:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 00:18:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 00:18:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 00:18:42 volumio volumio[28400]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 00:18:42 volumio volumio[28400]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:18:42 volumio volumio[28400]: info: [1770743922122] CoreMusicLibrary::Adding element Last_100 Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:18:42 volumio volumio[28400]: info: [1770743922166] CoreMusicLibrary::Adding element Webradio Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 00:18:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 00:18:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 00:18:42 volumio volumio[28400]: info: Initializing BBC Radios Feb 11 00:18:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 00:18:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 00:18:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 00:18:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:42 volumio volumio[28400]: info: Creating Spotify config file Feb 11 00:18:42 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:42 volumio sudo[28625]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 00:18:42 volumio sudo[28625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 00:18:42 volumio sudo[28625]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:43 volumio volumio[28533]: Starting albumart workers Feb 11 00:18:43 volumio volumio[28400]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:18:43 volumio volumio[28400]: info: [1770743923601] CoreMusicLibrary::Adding element YouTube Music Feb 11 00:18:43 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:43 volumio volumio[28400]: Cannot find translation for source YouTube Music Feb 11 00:18:43 volumio volumio[28532]: Starting albumart workers Feb 11 00:18:43 volumio volumio[28400]: info: Volumio Calling Home Feb 11 00:18:43 volumio sudo[28630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 00:18:43 volumio sudo[28630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:43 volumio sudo[28630]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:43 volumio volumio[28534]: Starting albumart workers Feb 11 00:18:44 volumio volumio[28400]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 00:18:44 volumio volumio[28400]: info: Discovery: Found device Volumio Feb 11 00:18:44 volumio volumio[28400]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:44 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:44 volumio volumio[28400]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 00:18:44 volumio volumio[28400]: info: Discovery: Found device Volumio Feb 11 00:18:44 volumio volumio[28400]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:44 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:44 volumio volumio[28400]: info: MPD Permissions set Feb 11 00:18:44 volumio volumio[28400]: info: MPD Permissions set Feb 11 00:18:44 volumio volumio[28400]: info: Upmpdcli Daemon Started Feb 11 00:18:44 volumio volumio[28400]: info: Volumio called home Feb 11 00:18:44 volumio volumio[28400]: info: Spotify config file written Feb 11 00:18:44 volumio sudo[28636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 00:18:44 volumio sudo[28636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 11 00:18:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:44 volumio go-librespot[28638]: go-librespot daemon starting... Feb 11 00:18:44 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 00:18:44 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 00:18:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:44 volumio go-librespot[28640]: go-librespot daemon starting... Feb 11 00:18:44 volumio sudo[28636]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=debug msg="app state loaded" Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:45 volumio volumio[28400]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:18:45 volumio volumio[28400]: info: No need to fix Spotify hosts Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:45 volumio go-librespot[28641]: time="2026-02-11T00:18:45+07:00" level=info msg="zeroconf server listening on port 35983" Feb 11 00:18:46 volumio go-librespot[28641]: time="2026-02-11T00:18:46+07:00" level=debug msg="obtained new client token: AAA6DAmlJo+rLXKu5GQAOX+mSYdioa2Ty+PqKIKnawXYXYT290VywfZAXayw4u9PfAyHBeFHRsQUuGPtyaHK9bjejxxV4nbh9GefHRd1ijJoxOFojXVM8V+NN1N7O9Eg3aUq0NxLTl3zeNQkjWvqNi4937+IRfkDXZfEm8MCqtQRc/OumhgdrcuCp6CtE+w/n1/wTwSwhtELGvRatEE1UdNcnuf5wOYOfkDzCBEo4D6+vjOYpCImvMo=" Feb 11 00:18:46 volumio go-librespot[28641]: time="2026-02-11T00:18:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:46 volumio go-librespot[28641]: time="2026-02-11T00:18:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:18:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:46 volumio volumio[28400]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 00:18:46 volumio volumio[28400]: SPOTIFY: BQCCOa1-mv2YQ_7wFDuJC7mTwmnXGvu8nvFvQkn-ajJ6-zcmrRaXF9W_xB8KlnPtaN6Q9zp0LtJR26PdbgHjffVWOkfi5m5kUls-Ajzd5bm6Hn7iGzzTPpLxIsFxkYHROzIIUMLVbERK0fVJMeQSSgoIlFL54qDzZElME8cjGW4rNVqW3oMHH_NaHiUZoz_XlUIADDBJKejxINR6mTJZj8mYW6YcQI42FVFFiIMi8yuO-Bdf8uNyFznI9LfgJ_rHUkxYsANPlBzFF9acW0Bb4uR-MmpU6XmlAI59cbkVo80q2dXJeq70CvDH Feb 11 00:18:46 volumio volumio[28400]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 00:18:46 volumio volumio[28400]: info: New Spotify access token = BQCCOa1-mv2YQ_7wFDuJC7mTwmnXGvu8nvFvQkn-ajJ6-zcmrRaXF9W_xB8KlnPtaN6Q9zp0LtJR26PdbgHjffVWOkfi5m5kUls-Ajzd5bm6Hn7iGzzTPpLxIsFxkYHROzIIUMLVbERK0fVJMeQSSgoIlFL54qDzZElME8cjGW4rNVqW3oMHH_NaHiUZoz_XlUIADDBJKejxINR6mTJZj8mYW6YcQI42FVFFiIMi8yuO-Bdf8uNyFznI9LfgJ_rHUkxYsANPlBzFF9acW0Bb4uR-MmpU6XmlAI59cbkVo80q2dXJeq70CvDH Feb 11 00:18:46 volumio volumio[28400]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 00:18:46 volumio volumio[28400]: info: Starting Shairport Sync Feb 11 00:18:46 volumio volumio[28400]: info: Starting Shairport Sync Feb 11 00:18:46 volumio volumio[28400]: info: Starting Shairport Sync Feb 11 00:18:46 volumio sudo[28677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:18:46 volumio sudo[28677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:46 volumio sudo[28679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:18:46 volumio sudo[28679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:46 volumio sudo[28681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:18:46 volumio sudo[28681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:18:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 00:18:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 00:18:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:46 volumio systemd[1]: shairport-sync.service: Consumed 2.285s CPU time. Feb 11 00:18:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:46 volumio sudo[28677]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:46 volumio volumio[28400]: info: Shairport-Sync Started Feb 11 00:18:46 volumio volumio[28400]: Error adding Membership: Error: addMembership EINVAL Feb 11 00:18:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 00:18:46 volumio volumio[28400]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:46 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 00:18:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:18:47 volumio sudo[28679]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:47 volumio sudo[28681]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:47 volumio volumio[28400]: info: Shairport-Sync Started Feb 11 00:18:47 volumio volumio[28400]: info: Shairport-Sync Started Feb 11 00:18:47 volumio volumio[28400]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 11 00:18:47 volumio volumio[28400]: info: Spotify Successfully logged in Feb 11 00:18:47 volumio volumio[28400]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:18:47 volumio volumio[28400]: info: [1770743927277] CoreMusicLibrary::Adding element Spotify Feb 11 00:18:47 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:18:47 volumio volumio[28400]: Cannot find translation for source YouTube Music Feb 11 00:18:47 volumio volumio[28400]: Cannot find translation for source Spotify Feb 11 00:18:47 volumio volumio[28400]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 00:18:47 volumio volumio[28400]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:18:48 volumio volumio[28400]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:18:48 volumio volumio[28400]: info: CoreCommandRouter::volumioGetState Feb 11 00:18:48 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:48 volumio volumio[28400]: info: CoreStateMachine::pushState Feb 11 00:18:48 volumio volumio[28400]: info: CorePlayQueue::getTrack 0 Feb 11 00:18:48 volumio volumio[28400]: info: CoreCommandRouter::volumioPushState Feb 11 00:18:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 00:18:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:49 volumio volumio[28400]: info: go-librespot daemon successfully initialized Feb 11 00:18:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:49 volumio go-librespot[28719]: go-librespot daemon starting... Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=debug msg="app state loaded" Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:49 volumio go-librespot[28720]: time="2026-02-11T00:18:49+07:00" level=info msg="zeroconf server listening on port 32859" Feb 11 00:18:50 volumio mpd[28628]: 2026-02-11T00:18:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 00:18:50 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 00:18:50 volumio sudo[28598]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:50 volumio sudo[28587]: pam_unix(sudo:session): session closed for user root Feb 11 00:18:50 volumio go-librespot[28720]: time="2026-02-11T00:18:50+07:00" level=debug msg="obtained new client token: AAASi0TSo40MWXouOwwfp/qLeh0BR+Q0VC3bbpkzEyAlC8Y2pskWGlw9ZWVjIIv0G/JX8sHS/Lmcie1YD0hZpfOXcgHS3Oy2i4uQsnDiKrrc+MiNbScwNMkBvFopnHyiNqSHHmjvk5TC3XU6PROc5TraRjaYoII2JrdEnZAHLYqXx1SayBaTIovKlnpTjufqnuQgas/9PBwKFxaBLcuY3tif5De/3dH8kTR3m9lKaNqj2tqEUF/TRws=" Feb 11 00:18:50 volumio volumio[28400]: error: MPD error: The expression evaluated to a falsy value: Feb 11 00:18:50 volumio volumio[28400]: assert.ok(self.idling) Feb 11 00:18:50 volumio volumio[28400]: error: The expression evaluated to a falsy value: Feb 11 00:18:50 volumio volumio[28400]: assert.ok(self.idling) Feb 11 00:18:50 volumio volumio[28400]: info: MPD running with PID28628 Feb 11 00:18:50 volumio volumio[28400]: ,establishing connection Feb 11 00:18:50 volumio volumio[28400]: error: updateQueue error: null Feb 11 00:18:50 volumio go-librespot[28720]: time="2026-02-11T00:18:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:50 volumio volumio[28400]: info: Completed starting Core Plugins Feb 11 00:18:50 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:50 volumio volumio[28400]: info: ----- MyVolumio plugins startup ---- Feb 11 00:18:50 volumio volumio[28400]: info: ------------------------------------------- Feb 11 00:18:50 volumio volumio[28400]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 00:18:50 volumio volumio[28400]: error: updateQueue error: null Feb 11 00:18:50 volumio go-librespot[28720]: time="2026-02-11T00:18:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:18:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:52 volumio volumio[28400]: info: Initializing connection to go-librespot Websocket Feb 11 00:18:52 volumio volumio[28400]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 00:18:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 00:18:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:53 volumio go-librespot[28731]: go-librespot daemon starting... Feb 11 00:18:53 volumio go-librespot[28732]: time="2026-02-11T00:18:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:53 volumio go-librespot[28732]: time="2026-02-11T00:18:53+07:00" level=debug msg="app state loaded" Feb 11 00:18:53 volumio go-librespot[28732]: time="2026-02-11T00:18:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=info msg="zeroconf server listening on port 39041" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="obtained new client token: AAAO/EEAoiJ/3kz9x8H+4r4bx7DCkuUaOoSXyltGEZ8xvpthrcr7myXd332F4mCvZ6hfOmdhLtCPnLoPTJq9PIBR+rCB4fKyerVqw5x2f0XsAP5l5sz1F5pte6cAw31nYof+rtnowkaH+MhTdTffPeLfq2x6kCKxa8rJqCsMREdYiSKVmkwPWG8uZT3yHZUKw+Gpcfx7zgfSPj/FpC/Vm1yd8i8c/RAo+snvs8mCEoP6JSYARKbExCiP6g==" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=debug msg="completed challenge" Feb 11 00:18:54 volumio go-librespot[28732]: time="2026-02-11T00:18:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:55 volumio volumio[28400]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 00:18:55 volumio volumio[28400]: info: Initializing connection to go-librespot Websocket Feb 11 00:18:55 volumio volumio[28400]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 00:18:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 00:18:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:18:57 volumio go-librespot[28739]: go-librespot daemon starting... Feb 11 00:18:57 volumio go-librespot[28740]: time="2026-02-11T00:18:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:18:57 volumio go-librespot[28740]: time="2026-02-11T00:18:57+07:00" level=debug msg="app state loaded" Feb 11 00:18:57 volumio go-librespot[28740]: time="2026-02-11T00:18:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:18:58 volumio volumio[28400]: info: Initializing connection to go-librespot Websocket Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=info msg="zeroconf server listening on port 38873" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="new websocket client" Feb 11 00:18:58 volumio volumio[28400]: info: Connection to go-librespot Websocket established Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="obtained new client token: AABl8A8pU+c0iutIUevwZFgWJXTQifD+Wy4dT+W4ZAXqofbpV+uv/8PxlaMrF3lWV+tYd7EzBD7mhiqTARPcG/jSV8PA2QGYK+PUTBSbFvforRPqlE2dAJN8sBee+lFNQ/rk+mrSkBa8ly1kObmklUtR7S+tzTLM65IMsopQnA5loueTVm/QezSctSGF0+aIjg9zDQcdNrjPjwxaR3NjYhG59d3tNtutDc6rkTjMPiCUh13Jk3CYrvcaUQ==" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="completed keyexchange" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=debug msg="completed challenge" Feb 11 00:18:58 volumio go-librespot[28740]: time="2026-02-11T00:18:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:18:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:18:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:18:58 volumio volumio[28400]: info: Connection to go-librespot Websocket closed Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 00:18:59 volumio volumio[28400]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 00:19:00 volumio volumio[28400]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 00:19:00 volumio volumio[28400]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 00:19:00 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:00 volumio volumio[28400]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:00 volumio volumio[28400]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 00:19:00 volumio volumio[28400]: info: MyVolumio login type: Token Feb 11 00:19:00 volumio volumio[28400]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 00:19:00 volumio volumio[28400]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 00:19:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 00:19:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:02 volumio go-librespot[28761]: go-librespot daemon starting... Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=debug msg="app state loaded" Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:02 volumio volumio[28400]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 00:19:02 volumio volumio[28400]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 00:19:02 volumio volumio[28400]: info: Streaming services startup Feb 11 00:19:02 volumio volumio[28400]: info: Starting Streaming Daemon Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:19:02 volumio sudo[28771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 00:19:02 volumio sudo[28771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:02 volumio volumio[28400]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 00:19:02 volumio go-librespot[28762]: time="2026-02-11T00:19:02+07:00" level=info msg="zeroconf server listening on port 45487" Feb 11 00:19:02 volumio sudo[28771]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:02 volumio volumio[28400]: info: Getting Spotify volume Feb 11 00:19:02 volumio volumio[28400]: info: Initializing connection to go-librespot Websocket Feb 11 00:19:03 volumio volumio[28400]: error: Cannot start Volumio Streaming Daemon Feb 11 00:19:03 volumio volumio[28400]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 00:19:03 volumio volumio[28400]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 00:19:03 volumio go-librespot[28762]: time="2026-02-11T00:19:03+07:00" level=debug msg="obtained new client token: AACp2gCXfI2/isqh2BFhRxqGpcaG+faY9mhkmfqTMaDxpQDlgAlshZr0tkdzMY4WTnZnxRj4SZwMzJHcSfTb+sHB7pJCObUHmvZGxbJ0mGL362Awk/djlfrp9l7d7Vc6AvQWvwIKnabIN24wCPVOXcOExWzXqWEPI3lb+Y2V90Fgbaj3HZnUVlWdiqynkLXgu2u41eFe7JP6zboXGf0BNHtH+pDFFsT/RGTMf5lnZ/+4/aNW1I5/" Feb 11 00:19:03 volumio go-librespot[28762]: time="2026-02-11T00:19:03+07:00" level=debug msg="new websocket client" Feb 11 00:19:03 volumio volumio[28400]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 11 00:19:03 volumio volumio[28400]: info: Connection to go-librespot Websocket established Feb 11 00:19:03 volumio go-librespot[28762]: time="2026-02-11T00:19:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:03 volumio go-librespot[28762]: time="2026-02-11T00:19:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:19:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:03 volumio volumio[28400]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 00:19:03 volumio volumio[28400]: Error: socket hang up Feb 11 00:19:03 volumio volumio[28400]: at connResetException (node:internal/errors:720:14) Feb 11 00:19:03 volumio volumio[28400]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 00:19:03 volumio volumio[28400]: at Socket.emit (node:events:526:35) Feb 11 00:19:03 volumio volumio[28400]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 00:19:03 volumio volumio[28400]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 00:19:03 volumio volumio[28400]: code: 'ECONNRESET', Feb 11 00:19:03 volumio volumio[28400]: response: undefined Feb 11 00:19:03 volumio volumio[28400]: } Feb 11 00:19:03 volumio volumio[28400]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 00:19:04 volumio sudo[28791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 00:18' Feb 11 00:19:04 volumio sudo[28791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:04 volumio sudo[28791]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:05 volumio volumio-remote-updater[643]: [2026-02-11 00:19:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 00:19:05 volumio volumio-remote-updater[643]: [2026-02-11 00:19:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 00:19:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 00:19:05 volumio systemd[1]: volumio.service: Consumed 55.519s CPU time. Feb 11 00:19:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 00:19:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10935. Feb 11 00:19:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 00:19:05 volumio systemd[1]: volumio.service: Consumed 55.519s CPU time. Feb 11 00:19:05 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 00:19:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 00:19:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 00:19:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:06 volumio go-librespot[28812]: go-librespot daemon starting... Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=debug msg="app state loaded" Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 00:19:06 volumio go-librespot[28813]: time="2026-02-11T00:19:06+07:00" level=info msg="zeroconf server listening on port 35799" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19:07+07:00" level=debug msg="obtained new client token: AABXYaQ5EYFofcA1m22kv70sPbidU9+4ukfdW/kQ+q8OjCMl2P8NMnHfL83ELlOldQFJA6ZAlQ0BSyL6EyaoXLQdjEM1Mn9MtUk+0jtM6DcKDGTjLfeg6of7M3wdKLsDSDxBgz9TsrklIRuViYh0YW1az14GjtKMEwHGzkfB3FqERDv32tXL8dmxt4eBKkB3OIGIK+KlG/Z2no8vEdN4u3E36EPlY/wx6ZL4GWVhMjO+ALmfCdQ60eU=" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19:07+07:00" level=debug msg="completed keyexchange" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19:07+07:00" level=debug msg="completed challenge" Feb 11 00:19:07 volumio go-librespot[28813]: time="2026-02-11T00:19: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 11 00:19:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:08 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:08 volumio volumio[28800]: info: ----- Volumio3 ---- Feb 11 00:19:08 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:08 volumio volumio[28800]: info: ----- System startup ---- Feb 11 00:19:08 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:10 volumio volumio-remote-updater[643]: [2026-02-11 00:19:10] [connect] Successful connection Feb 11 00:19:10 volumio volumio[28800]: info: MYVOLUMIO Environment detected Feb 11 00:19:10 volumio volumio[28800]: info: Plugin folders cleanup Feb 11 00:19:10 volumio volumio[28800]: info: Scanning into folder /volumio/app/plugins/ Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category audio_interface Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category miscellanea Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category music_service Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category plugins.json Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category system_controller Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category user_interface Feb 11 00:19:10 volumio volumio[28800]: info: Scanning into folder /data/plugins/ Feb 11 00:19:10 volumio volumio[28800]: info: Scanning category music_service Feb 11 00:19:10 volumio volumio[28800]: info: Plugin folders cleanup completed Feb 11 00:19:10 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:10 volumio volumio[28800]: info: ----- Core plugins startup ---- Feb 11 00:19:10 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:10 volumio volumio[28800]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 00:19:10 volumio volumio[28800]: info: Adding plugin upnp to MyMusic Plugins Feb 11 00:19:10 volumio volumio[28800]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 00:19:10 volumio volumio[28800]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 00:19:10 volumio volumio[28800]: info: Loading plugins from folder /data/plugins/ Feb 11 00:19:10 volumio volumio[28800]: info: Loading plugin "system"... Feb 11 00:19:10 volumio volumio[28800]: info: Loading plugin "appearance"... Feb 11 00:19:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 00:19:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:10 volumio go-librespot[28834]: go-librespot daemon starting... Feb 11 00:19:10 volumio go-librespot[28835]: time="2026-02-11T00:19:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:10 volumio go-librespot[28835]: time="2026-02-11T00:19:10+07:00" level=debug msg="app state loaded" Feb 11 00:19:10 volumio go-librespot[28835]: time="2026-02-11T00:19:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=info msg="zeroconf server listening on port 45187" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=debug msg="obtained new client token: AABaGzxpxU7zo3MtIZ4V+0wUfEYpzzZjBGxbRI+zXK03LnX3YpudDBnm7pPb7yZH+tf23AokSsh+fjEA04JIX/Fpi/llgt5Pjld44zp7zjgLFzTbW0Q7YT0tjK39GuqYzXL75cbitI9GdAylz1dpjkaE2mmDaO1xjK9Lw0ohfh1FpjOFWP2YT17bt4fZHcTx7YI9tnjGI9A0mmpyKPM8Tl/UBLO2z/1gGxEM7acnAuwD27llph3o7fzPdg==" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:11 volumio go-librespot[28835]: time="2026-02-11T00:19:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:19:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "network"... Feb 11 00:19:12 volumio volumio[28800]: info: Refreshing Cached IP Addresses Feb 11 00:19:12 volumio sudo[28844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 00:19:12 volumio sudo[28844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:12 volumio sudo[28844]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "services"... Feb 11 00:19:12 volumio sudo[28846]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "alsa_controller"... Feb 11 00:19:12 volumio sudo[28846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:12 volumio sudo[28854]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 00:19:12 volumio sudo[28854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:12 volumio sudo[28846]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:12 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "wizard"... Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "networkfs"... Feb 11 00:19:12 volumio volumio[28800]: info: Starting Udev Watcher for removable devices Feb 11 00:19:12 volumio volumio[28800]: info: Ignoring mount for partition: boot Feb 11 00:19:12 volumio volumio[28800]: info: Ignoring mount for partition: volumio Feb 11 00:19:12 volumio volumio[28800]: info: Ignoring mount for partition: volumio_data Feb 11 00:19:12 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "volumio_command_line_client"... Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "upnp"... Feb 11 00:19:12 volumio volumio[28800]: info: [1770743952836] Starting Upmpd Daemon Feb 11 00:19:12 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "my_music"... Feb 11 00:19:12 volumio volumio[28800]: info: Loading plugin "mpd"... Feb 11 00:19:13 volumio volumio[28800]: info: Loading plugin "upnp_browser"... Feb 11 00:19:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 00:19:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:15 volumio go-librespot[28877]: go-librespot daemon starting... Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=debug msg="app state loaded" Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:15 volumio sudo[28854]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=info msg="zeroconf server listening on port 37027" Feb 11 00:19:15 volumio go-librespot[28878]: time="2026-02-11T00:19:15+07:00" level=debug msg="obtained new client token: AACaYxru5JhZ2ETVoMjQ2bZD9cYzLmtegNSefn9WLT/n2VTigQnivDH0ZnLkQMcr9YWLOzvdB2FlaA8ifLKYNDRMK3d6oBTQm5+Yabvu1oHFqAfQuzkn+DyE1AYupBEDeBobveFGTwuc6FkAn9gYM/+l9CMGbIgLJc2hd4X3mUOjGpWcApAXjFniAJwjleGOAnA0adW+v5XVsGjUuueEWr/DzSKsNtaBEEnuE6+A8RNJ3d8NYMIFtf0gVg==" Feb 11 00:19:16 volumio go-librespot[28878]: time="2026-02-11T00:19:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:16 volumio go-librespot[28878]: time="2026-02-11T00:19:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:19:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:16 volumio volumio[28800]: info: Starting UPNP Browser Feb 11 00:19:16 volumio volumio[28800]: info: Loading plugin "alarm-clock"... Feb 11 00:19:16 volumio volumio[28800]: info: Loading plugin "airplay_emulation"... Feb 11 00:19:16 volumio volumio[28800]: info: Starting Shairport Sync Feb 11 00:19:16 volumio volumio[28800]: info: Loading plugin "last_100"... Feb 11 00:19:16 volumio volumio[28800]: info: Loading plugin "webradio"... Feb 11 00:19:16 volumio volumio[28800]: info: Loading plugin "i2s_dacs"... Feb 11 00:19:16 volumio volumio[28800]: info: Loading plugin "volumiodiscovery"... Feb 11 00:19:17 volumio volumio[28800]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 00:19:17 volumio volumio[28800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:19:17 volumio volumio[28800]: *** WARNING *** For more information see Feb 11 00:19:17 volumio volumio[28800]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 00:19:17 volumio volumio[28800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:19:17 volumio volumio[28800]: *** WARNING *** For more information see Feb 11 00:19:17 volumio node[28800]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 00:19:17 volumio node[28800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:19:17 volumio node[28800]: *** WARNING *** For more information see Feb 11 00:19:17 volumio node[28800]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 00:19:17 volumio node[28800]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 00:19:17 volumio node[28800]: *** WARNING *** For more information see Feb 11 00:19:17 volumio volumio[28800]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 00:19:17 volumio volumio[28800]: info: Discovery: Started advertising with name: Volumio Feb 11 00:19:17 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 00:19:17 volumio volumio[28800]: info: Loading plugin "spop"... Feb 11 00:19:18 volumio volumio[28800]: info: Loading plugin "ytcr"... Feb 11 00:19:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 00:19:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:19 volumio go-librespot[28889]: go-librespot daemon starting... Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19:19+07:00" level=debug msg="app state loaded" Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:19:19 volumio go-librespot[28890]: time="2026-02-11T00:19:19+07:00" level=info msg="zeroconf server listening on port 38707" Feb 11 00:19:20 volumio go-librespot[28890]: time="2026-02-11T00:19:20+07:00" level=debug msg="obtained new client token: AACciWrY+Wjej4xK8EyvvGq8aUQcj6JA86zDD0oPAA6XrcUxfYt4qgCG434pi/aUI+X6oVK6Q6+FuF5NnvDF1USs8jO6EGlB+rOXkpBMxJdHfyCkzSeq5RS4/A4A6XnmYtri/AEcTg4mfZfMqhuY4SD0LYthf8x3j8tDtY3La2hf05wjpycjOUN74duFoB1+aFpPEv3gUn1HL4tgcPj0ooqM73/KrNWnW/LTqWkmC8CDjLNUlHjYMRY=" Feb 11 00:19:20 volumio go-librespot[28890]: time="2026-02-11T00:19:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:20 volumio go-librespot[28890]: time="2026-02-11T00:19:20+07:00" level=debug msg="completed keyexchange" Feb 11 00:19:20 volumio go-librespot[28890]: time="2026-02-11T00:19:20+07:00" level=debug msg="completed challenge" Feb 11 00:19:20 volumio go-librespot[28890]: time="2026-02-11T00:19:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 11 00:19:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:21 volumio volumio[28800]: info: Loading plugin "ytmusic"... Feb 11 00:19:22 volumio volumio-remote-updater[643]: [2026-02-11 00:19:22] [connect] Successful connection Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "outputs"... Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "albumart"... Feb 11 00:19:22 volumio volumio[28800]: info: Plugin example_plugin is not enabled Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "inputs"... Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "updater_comm"... Feb 11 00:19:22 volumio volumio[28800]: info: Plugin mpdemulation is not enabled Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "rest_api"... Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "websocket"... Feb 11 00:19:22 volumio volumio[28800]: info: Starting Socket.io Server version 1.7.4 Feb 11 00:19:22 volumio volumio[28800]: info: Loading plugin "RoonBridge"... Feb 11 00:19:23 volumio volumio[28800]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 00:19:23 volumio volumio[28800]: info: Loading i18n strings for locale en Feb 11 00:19:23 volumio volumio[28800]: Updating browse sources language Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:19:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 00:19:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:23 volumio go-librespot[28921]: go-librespot daemon starting... Feb 11 00:19:23 volumio go-librespot[28922]: time="2026-02-11T00:19:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:23 volumio go-librespot[28922]: time="2026-02-11T00:19:23+07:00" level=debug msg="app state loaded" Feb 11 00:19:23 volumio go-librespot[28922]: time="2026-02-11T00:19:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::initPlayerControls Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 00:19:23 volumio volumio[28800]: Express server listening on port 3000 Feb 11 00:19:23 volumio volumio[28800]: [Metrics] WebUI: 15s 868.40ms Feb 11 00:19:23 volumio volumio[28911]: Forking 3 albumart workers Feb 11 00:19:23 volumio volumio[28800]: info: CoreStateMachine::resetVolumioState Feb 11 00:19:23 volumio volumio[28800]: info: CoreStateMachine::getcurrentVolume Feb 11 00:19:23 volumio volumio[28800]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:19:24 volumio sudo[28952]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 00:19:24 volumio sudo[28952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:24 volumio sudo[28952]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:24 volumio sudo[28962]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 00:19:24 volumio sudo[28962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:24 volumio sudo[28962]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:24 volumio volumio[28800]: info: Volumio Network Manager: Network status updated: 1 Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=info msg="zeroconf server listening on port 45351" Feb 11 00:19:24 volumio volumio[28800]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:19:24 volumio volumio[28800]: info: CoreStateMachine::pushState Feb 11 00:19:24 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::volumioPushState Feb 11 00:19:24 volumio volumio[28800]: info: CoreStateMachine::updateTrackBlock Feb 11 00:19:24 volumio volumio[28800]: info: CorePlayQueue::getTrackBlock Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="obtained new client token: AADzpFQK+b+Uw5QBsbQaMBwIsEKjN4/PnCqOXsFtl0QARlXkdCpuqQEyscI3GqeTVICp7H46iNyizttOPik8jTRZx8KD3P6Ad6kAWwb8k27S7IChmSpTVKXGw3qbzyE+HaCgVfkaIj+ZF7yhV5ffetvxgSFuOGYRIsgRI2q/bI0ZaeWuREtS4TuAP+tsMxo3NW1F4TKAXP2HxJ7G2Wdnbd0/iPkXOqh0om5DXIn5OTsNgov/msyBrZWfew==" Feb 11 00:19:24 volumio volumio-remote-updater[643]: [2026-02-11 00:19:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770743962 101 Feb 11 00:19:24 volumio volumio[28800]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:24 volumio volumio[28800]: info: Reloading queue from file Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 00:19:24 volumio volumio[28800]: info: CoreStateMachine::setRepeat null single undefined Feb 11 00:19:24 volumio volumio[28800]: info: CoreStateMachine::pushState Feb 11 00:19:24 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::volumioPushState Feb 11 00:19:24 volumio volumio[28800]: info: CoreStateMachine::setRandom null Feb 11 00:19:24 volumio volumio[28800]: info: CoreStateMachine::pushState Feb 11 00:19:24 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:24 volumio volumio[28800]: info: CoreCommandRouter::volumioPushState Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="completed keyexchange" Feb 11 00:19:24 volumio go-librespot[28922]: time="2026-02-11T00:19:24+07:00" level=debug msg="completed challenge" Feb 11 00:19:24 volumio volumio[28800]: info: Setting Device type: Raspberry PI Feb 11 00:19:25 volumio go-librespot[28922]: time="2026-02-11T00:19: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 11 00:19:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:25 volumio volumio[28800]: info: Completed loading Core Plugins Feb 11 00:19:25 volumio volumio[28800]: info: Preparing to generate the ALSA configuration file Feb 11 00:19:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:25 volumio volumio[28800]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:19:25 volumio volumio[28800]: info: CoreStateMachine::pushState Feb 11 00:19:25 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::volumioPushState Feb 11 00:19:25 volumio volumio[28800]: info: Asound.conf file unchanged, so no further update is needed Feb 11 00:19:25 volumio volumio[28800]: info: Output device has changed, restarting MPD Feb 11 00:19:25 volumio volumio[28800]: info: Output device has changed, restarting Shairport Sync Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:25 volumio sudo[28980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 00:19:25 volumio sudo[28980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:25 volumio volumio[28800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 00:19:25 volumio volumio[28800]: info: ___________ START PLUGINS ___________ Feb 11 00:19:25 volumio sudo[28985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 00:19:25 volumio sudo[28985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:25 volumio volumio[28800]: info: ControllerMpd::onStart: Initializing MPD Feb 11 00:19:25 volumio volumio[28800]: info: Creating MPD Configuration file Feb 11 00:19:25 volumio sudo[28982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 00:19:25 volumio sudo[28982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:25 volumio sudo[28982]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:19:25 volumio volumio[28800]: info: [1770743965492] CoreMusicLibrary::Adding element Media Servers Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:19:25 volumio sudo[28993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 00:19:25 volumio sudo[28993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:25 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 00:19:25 volumio volumio[28800]: info: UPNP Browser: Client initialized successfully Feb 11 00:19:25 volumio sudo[28995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 00:19:25 volumio sudo[28980]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:25 volumio sudo[28995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:25 volumio sudo[28993]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:25 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 00:19:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 00:19:25 volumio systemd[1]: mpd.service: Consumed 7.285s CPU time. Feb 11 00:19:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 00:19:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 00:19:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 00:19:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 00:19:25 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 00:19:25 volumio volumio[28800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 00:19:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 00:19:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 00:19:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 00:19:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 00:19:25 volumio volumio[28800]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:19:25 volumio volumio[28800]: info: [1770743965979] CoreMusicLibrary::Adding element Last_100 Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:19:25 volumio volumio[28800]: info: [1770743965989] CoreMusicLibrary::Adding element Webradio Feb 11 00:19:25 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:19:26 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 00:19:26 volumio volumio[28800]: info: Initializing BBC Radios Feb 11 00:19:26 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 00:19:26 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:26 volumio volumio[28800]: info: Creating Spotify config file Feb 11 00:19:26 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:26 volumio sudo[29007]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 00:19:26 volumio sudo[29007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 00:19:26 volumio sudo[29007]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:27 volumio volumio[28930]: Starting albumart workers Feb 11 00:19:27 volumio volumio[28932]: Starting albumart workers Feb 11 00:19:27 volumio volumio[28933]: Starting albumart workers Feb 11 00:19:27 volumio volumio[28800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:19:27 volumio volumio[28800]: info: [1770743967439] CoreMusicLibrary::Adding element YouTube Music Feb 11 00:19:27 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:19:27 volumio volumio[28800]: Cannot find translation for source YouTube Music Feb 11 00:19:27 volumio volumio[28800]: info: Volumio Calling Home Feb 11 00:19:27 volumio sudo[29026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 00:19:27 volumio sudo[29026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:27 volumio sudo[29026]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:28 volumio volumio[28800]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 00:19:28 volumio volumio[28800]: info: Discovery: Found device Volumio Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::volumioGetState Feb 11 00:19:28 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:28 volumio volumio[28800]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 00:19:28 volumio volumio[28800]: info: Discovery: Found device Volumio Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::volumioGetState Feb 11 00:19:28 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 11 00:19:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:28 volumio volumio[28800]: info: MPD Permissions set Feb 11 00:19:28 volumio volumio[28800]: info: MPD Permissions set Feb 11 00:19:28 volumio volumio[28800]: info: Upmpdcli Daemon Started Feb 11 00:19:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:28 volumio go-librespot[29032]: go-librespot daemon starting... Feb 11 00:19:28 volumio volumio[28800]: info: Spotify config file written Feb 11 00:19:28 volumio go-librespot[29033]: time="2026-02-11T00:19:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:28 volumio go-librespot[29033]: time="2026-02-11T00:19:28+07:00" level=debug msg="app state loaded" Feb 11 00:19:28 volumio go-librespot[29033]: time="2026-02-11T00:19:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:28 volumio volumio[28800]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 00:19:28 volumio sudo[29040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 00:19:28 volumio volumio[28800]: info: Volumio called home Feb 11 00:19:28 volumio sudo[29040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio systemd[1]: go-librespot-daemon.service: Killing process 29037 (go-librespot) with signal SIGKILL. Feb 11 00:19:28 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 00:19:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 00:19:28 volumio volumio[28800]: info: No need to fix Spotify hosts Feb 11 00:19:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:28 volumio go-librespot[29048]: go-librespot daemon starting... Feb 11 00:19:28 volumio sudo[29040]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=debug msg="app state loaded" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=info msg="zeroconf server listening on port 39363" Feb 11 00:19:29 volumio go-librespot[29053]: time="2026-02-11T00:19:29+07:00" level=debug msg="obtained new client token: AABO2EWSrO1zvQLbM/HUQ9Y40R8b61bTQBr08UDXqvp3YkR7B4kuSXjfHehGhWUkM8h+Z3L4dXgetPS5qrfZVT3PNXrYzevp1OSyiJ0KNh3rKF+nBU6CTm8p2NUqJNJ8zM1zHJrS2bP1cpwH/+RFngxhT40c/Ec18W70lwNmQL5J0uus+cE90hGBkEN174d7CGtw/a4AkJAwT5kHxK9WsDMhrkbA/fWNhA3PGgHpapXzVIKAtKlPyK0ZUA==" Feb 11 00:19:30 volumio volumio[28800]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 00:19:30 volumio volumio[28800]: SPOTIFY: BQAyazTeyJh-pGM9AxdrJxT9SFYu7zlRhBm-i0JaRh7Aq2i1AWMCZvMEnJXTMiW-Y7dYb9eEW-jcCbsA7DrTNtjgh5LRohorW_6MPGHU3OX-YFSvaU3uSLVSATaEvWrHuHfmkq5eG4bmfzd7ZMA0Oau0N2yTCD0NXulFXaJglvclLInVes62FiEzdYDcmfnQ1vawduXdyZUlHflzeHKCSaaREKn1sfgyQps056JfeDIbLDzMWlwXQakLcYMTxXk1LkNrrPLVGvgNcSYugk8FPU4lk9AWfpdtvzxVE2W7Aki1NeWXaQWER1ii Feb 11 00:19:30 volumio volumio[28800]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 00:19:30 volumio volumio[28800]: info: New Spotify access token = BQAyazTeyJh-pGM9AxdrJxT9SFYu7zlRhBm-i0JaRh7Aq2i1AWMCZvMEnJXTMiW-Y7dYb9eEW-jcCbsA7DrTNtjgh5LRohorW_6MPGHU3OX-YFSvaU3uSLVSATaEvWrHuHfmkq5eG4bmfzd7ZMA0Oau0N2yTCD0NXulFXaJglvclLInVes62FiEzdYDcmfnQ1vawduXdyZUlHflzeHKCSaaREKn1sfgyQps056JfeDIbLDzMWlwXQakLcYMTxXk1LkNrrPLVGvgNcSYugk8FPU4lk9AWfpdtvzxVE2W7Aki1NeWXaQWER1ii Feb 11 00:19:30 volumio volumio[28800]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 00:19:30 volumio go-librespot[29053]: time="2026-02-11T00:19:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:30 volumio volumio[28800]: info: Starting Shairport Sync Feb 11 00:19:30 volumio volumio[28800]: info: Starting Shairport Sync Feb 11 00:19:30 volumio volumio[28800]: info: Starting Shairport Sync Feb 11 00:19:30 volumio sudo[29079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:19:30 volumio sudo[29079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:30 volumio sudo[29083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:19:30 volumio sudo[29083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:30 volumio sudo[29082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 00:19:30 volumio sudo[29082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 00:19:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 00:19:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 00:19:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:19:30 volumio systemd[1]: shairport-sync.service: Consumed 2.315s CPU time. Feb 11 00:19:30 volumio go-librespot[29053]: time="2026-02-11T00:19:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.23:46498->104.199.241.202:4070: read: connection reset by peer" Feb 11 00:19:30 volumio volumio[28800]: info: CoreCommandRouter::volumioGetState Feb 11 00:19:30 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 00:19:30 volumio sudo[29082]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:30 volumio sudo[29079]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:30 volumio sudo[29083]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:30 volumio volumio[28800]: info: Shairport-Sync Started Feb 11 00:19:30 volumio volumio[28800]: Error adding Membership: Error: addMembership EINVAL Feb 11 00:19:30 volumio volumio[28800]: info: Shairport-Sync Started Feb 11 00:19:30 volumio volumio[28800]: info: Shairport-Sync Started Feb 11 00:19:30 volumio volumio[28800]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 11 00:19:30 volumio volumio[28800]: info: Spotify Successfully logged in Feb 11 00:19:30 volumio volumio[28800]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 00:19:30 volumio volumio[28800]: info: [1770743970784] CoreMusicLibrary::Adding element Spotify Feb 11 00:19:30 volumio volumio[28800]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 00:19:30 volumio volumio[28800]: Cannot find translation for source YouTube Music Feb 11 00:19:30 volumio volumio[28800]: Cannot find translation for source Spotify Feb 11 00:19:31 volumio volumio[28800]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 00:19:31 volumio volumio[28800]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 00:19:31 volumio volumio[28800]: info: VolumeController:: Volume=100 Mute =false Feb 11 00:19:31 volumio volumio[28800]: info: CoreCommandRouter::volumioGetState Feb 11 00:19:31 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:31 volumio volumio[28800]: info: CoreStateMachine::pushState Feb 11 00:19:31 volumio volumio[28800]: info: CorePlayQueue::getTrack 0 Feb 11 00:19:31 volumio volumio[28800]: info: CoreCommandRouter::volumioPushState Feb 11 00:19:33 volumio volumio[28800]: info: go-librespot daemon successfully initialized Feb 11 00:19:33 volumio mpd[29024]: 2026-02-11T00:19:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 00:19:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 00:19:33 volumio sudo[28995]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:33 volumio sudo[28985]: pam_unix(sudo:session): session closed for user root Feb 11 00:19:33 volumio volumio[28800]: error: MPD error: The expression evaluated to a falsy value: Feb 11 00:19:33 volumio volumio[28800]: assert.ok(self.idling) Feb 11 00:19:33 volumio volumio[28800]: error: The expression evaluated to a falsy value: Feb 11 00:19:33 volumio volumio[28800]: assert.ok(self.idling) Feb 11 00:19:33 volumio volumio[28800]: info: MPD running with PID29024 Feb 11 00:19:33 volumio volumio[28800]: ,establishing connection Feb 11 00:19:33 volumio volumio[28800]: error: updateQueue error: null Feb 11 00:19:33 volumio volumio[28800]: info: Completed starting Core Plugins Feb 11 00:19:33 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:33 volumio volumio[28800]: info: ----- MyVolumio plugins startup ---- Feb 11 00:19:33 volumio volumio[28800]: info: ------------------------------------------- Feb 11 00:19:33 volumio volumio[28800]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 00:19:33 volumio volumio[28800]: error: updateQueue error: null Feb 11 00:19:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 00:19:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:33 volumio go-librespot[29125]: go-librespot daemon starting... Feb 11 00:19:33 volumio go-librespot[29126]: time="2026-02-11T00:19:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:33 volumio go-librespot[29126]: time="2026-02-11T00:19:33+07:00" level=debug msg="app state loaded" Feb 11 00:19:33 volumio go-librespot[29126]: time="2026-02-11T00:19:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19: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 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19: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 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19: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 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19:34+07:00" level=info msg="zeroconf server listening on port 45653" Feb 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19:34+07:00" level=debug msg="obtained new client token: AACe6Um9nfG9qf34yXkNGYn6CIohxsJZZNaQW4WTxGWJ4QeIEzmOjXYfgO1KnzmShIVIipr0oJmaQBeUmc8OGofUVKzibaiL+RIMqu8mEAReCcgzAw1JGhsfPGdLzvO2Ny/jGQ8rt9TlVDeiTPzQbnz6nJ2faH100wQBOvEVLSe5PEuCRAyZ4LEELXG/UZXb/uEVR/QsZmX8cULKxVI4svHJk2y4B6eywiudDE9vZrjQIfSD5B1FzBwR8w==" Feb 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:34 volumio go-librespot[29126]: time="2026-02-11T00:19:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:19:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:36 volumio volumio[28800]: info: Initializing connection to go-librespot Websocket Feb 11 00:19:36 volumio volumio[28800]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 00:19:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 00:19:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:38 volumio go-librespot[29133]: go-librespot daemon starting... Feb 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19:38+07:00" level=debug msg="app state loaded" Feb 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:38 volumio volumio[28800]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19: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 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19: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 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19: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 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19:38+07:00" level=info msg="zeroconf server listening on port 43771" Feb 11 00:19:38 volumio go-librespot[29134]: time="2026-02-11T00:19:38+07:00" level=debug msg="obtained new client token: AABkkqqvvpn43rLeeEoH+Eg5akeLl4aXx7IDad3V6avE8H+xpFRZArebW8XCQpK5cETIZiqyztGYz2LDUIalKiB2+F9CBgCnsDPy3QOMJNcQKxphWXRki6nqT2b73UyYkNAtbbwg77FQqTxgTG1kePk4gfK6PzcriNmSsn+8psCO6Cy6OmAi1crDz6+dLoEixRDgYl19f5XWixoTAAmLn70c0KXmv7mPv2khH7lkWBvUKPBA5Q+vDFCn4A==" Feb 11 00:19:39 volumio go-librespot[29134]: time="2026-02-11T00:19:39+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 11 00:19:39 volumio volumio[28800]: info: Initializing connection to go-librespot Websocket Feb 11 00:19:39 volumio go-librespot[29134]: time="2026-02-11T00:19:39+07:00" level=debug msg="new websocket client" Feb 11 00:19:39 volumio volumio[28800]: info: Connection to go-librespot Websocket established Feb 11 00:19:39 volumio go-librespot[29134]: time="2026-02-11T00:19:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 00:19:39 volumio go-librespot[29134]: time="2026-02-11T00:19:39+07:00" level=debug msg="completed keyexchange" Feb 11 00:19:39 volumio go-librespot[29134]: time="2026-02-11T00:19:39+07:00" level=debug msg="completed challenge" Feb 11 00:19:39 volumio go-librespot[29134]: time="2026-02-11T00:19: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 11 00:19:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:39 volumio volumio[28800]: info: Connection to go-librespot Websocket closed Feb 11 00:19:42 volumio volumio[28800]: info: Getting Spotify volume Feb 11 00:19:42 volumio volumio[28800]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 00:19:42 volumio volumio[28800]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 00:19:42 volumio volumio[28800]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 00:19:42 volumio volumio[28800]: errno: -111, Feb 11 00:19:42 volumio volumio[28800]: code: 'ECONNREFUSED', Feb 11 00:19:42 volumio volumio[28800]: syscall: 'connect', Feb 11 00:19:42 volumio volumio[28800]: address: '127.0.0.1', Feb 11 00:19:42 volumio volumio[28800]: port: 9879, Feb 11 00:19:42 volumio volumio[28800]: response: undefined Feb 11 00:19:42 volumio volumio[28800]: } Feb 11 00:19:42 volumio volumio[28800]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 00:19:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 00:19:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 00:19:42 volumio go-librespot[29153]: go-librespot daemon starting... Feb 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19:42+07:00" level=debug msg="app state loaded" Feb 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19: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 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19: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 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19: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 11 00:19:42 volumio go-librespot[29154]: time="2026-02-11T00:19:42+07:00" level=info msg="zeroconf server listening on port 39341" Feb 11 00:19:43 volumio go-librespot[29154]: time="2026-02-11T00:19:43+07:00" level=debug msg="obtained new client token: AAAzhHNhFBPS9AGiQRD0xi+KHhQkEJsAshB1y/2lRDET4c17QG/ak32vgt9dS1tDR9S8PBC9Tlx/HRfLgZaYebPnrecX8JRsV1PpNypqqTQtk7Ay3Rvd4IR9vaP4G4c6qmrMuOLT7BzFbPClpsVxkTcCBHOs2kHyVqQYKuXizbf1jjR5OgLLGG25iwVbT0RGWK4AERbN/VVYqxQgjqRQcFbU4MVDRpact2jDjUnN6j4Ey/b0ytUy5lw=" Feb 11 00:19:43 volumio go-librespot[29154]: time="2026-02-11T00:19:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 00:19:43 volumio go-librespot[29154]: time="2026-02-11T00:19:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 11 00:19:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 00:19:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 00:19:43 volumio sudo[29180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 00:18' Feb 11 00:19:43 volumio sudo[29180]: 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"