Feb 18 05:48:00 volumio go-librespot[8124]: time="2026-02-18T05:48:00+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:00 volumio go-librespot[8124]: time="2026-02-18T05:48:00+07:00" level=debug msg="completed challenge" Feb 18 05:48:00 volumio go-librespot[8124]: time="2026-02-18T05:48:00+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 18 05:48:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:00 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:48:00 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:00 volumio volumio[7954]: info: Creating Spotify config file Feb 18 05:48:00 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:00 volumio sudo[8163]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 05:48:00 volumio sudo[8163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 05:48:00 volumio sudo[8163]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:01 volumio volumio[8082]: Starting albumart workers Feb 18 05:48:01 volumio volumio[8077]: Starting albumart workers Feb 18 05:48:01 volumio volumio[7954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:01 volumio volumio[7954]: info: [1771368481315] CoreMusicLibrary::Adding element YouTube Music Feb 18 05:48:01 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:01 volumio volumio[7954]: Cannot find translation for source YouTube Music Feb 18 05:48:01 volumio volumio[7954]: info: Volumio Calling Home Feb 18 05:48:01 volumio sudo[8183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 05:48:01 volumio sudo[8183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:01 volumio sudo[8183]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:01 volumio volumio[8081]: Starting albumart workers Feb 18 05:48:02 volumio volumio[7954]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 05:48:02 volumio volumio[7954]: info: Discovery: Found device Volumio Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:02 volumio volumio[7954]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:02 volumio volumio[7954]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 05:48:02 volumio volumio[7954]: info: Discovery: Found device Volumio Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:02 volumio volumio[7954]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:02 volumio volumio[7954]: info: MPD Permissions set Feb 18 05:48:02 volumio volumio[7954]: info: MPD Permissions set Feb 18 05:48:02 volumio volumio[7954]: info: Upmpdcli Daemon Started Feb 18 05:48:02 volumio volumio[7954]: info: Spotify config file written Feb 18 05:48:02 volumio volumio[7954]: 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 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio sudo[8189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio sudo[8189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:02 volumio volumio[7954]: info: No need to fix Spotify hosts Feb 18 05:48:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:02 volumio go-librespot[8201]: go-librespot daemon starting... Feb 18 05:48:02 volumio sudo[8189]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:02 volumio go-librespot[8202]: time="2026-02-18T05:48:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:02 volumio go-librespot[8202]: time="2026-02-18T05:48:02+07:00" level=debug msg="app state loaded" Feb 18 05:48:02 volumio go-librespot[8202]: time="2026-02-18T05:48:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:03 volumio volumio[7954]: info: Volumio called home Feb 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+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 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+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 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+07:00" level=info msg="zeroconf server listening on port 38463" Feb 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+07:00" level=debug msg="obtained new client token: AADT2ZXOg8kbNzRQ6dHJ0zT//+oRk2yWF4ovrkaJQjUpNsQb0Cphx8ibNLUzq3FluPIWikp8uHnMqXMBfkNb/TF5HSwoXSiMkIkIsD13y7NWDz3Fmrch/fLFGkEAbQu+BLIfiKwZK0mYC/vB+oRRQEA0kAcxXWtkwQPjnUy/gNmlNWD0qBIq5zgGYg10BtmZCyw5hEAsXw9ZjBg0gRxRyY62kal+7tzZwIb/vgf8iF5LN4YmUs2BkRLPPw==" Feb 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:03 volumio go-librespot[8202]: time="2026-02-18T05:48:03+07:00" level=debug msg="completed challenge" Feb 18 05:48:04 volumio volumio[7954]: info: Starting Shairport Sync Feb 18 05:48:04 volumio volumio[7954]: info: Starting Shairport Sync Feb 18 05:48:04 volumio volumio[7954]: info: Starting Shairport Sync Feb 18 05:48:04 volumio go-librespot[8202]: time="2026-02-18T05:48:04+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 18 05:48:04 volumio sudo[8229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:48:04 volumio sudo[8229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:04 volumio sudo[8234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:48:04 volumio sudo[8234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:04 volumio sudo[8231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:48:04 volumio sudo[8231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 05:48:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 05:48:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 05:48:04 volumio systemd[1]: shairport-sync.service: Consumed 2.426s CPU time. Feb 18 05:48:04 volumio volumio[7954]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 05:48:04 volumio volumio[7954]: SPOTIFY: BQDDGnUgiqwsY9NpmOPSCBmCv3lpjEiYLsxX2_I4gliBps9MTtKuLamn3jIct3guFJbqwRBV6pp7kRd-wB89Vpfg4db5ekRK52Kgfl-gyfFZfOnZfHhkP53xe1rG_mVF_OdWwiMcgsQTSioPoOeblHVA923DsmyjpWmDlh-ejLugys5YeHXYEJ_fFRhrkNjRWnz1UP-SY-3s8zrP6_KGCRrlxhNG8hvHpBLMNDsdCnT08lt3oAiM0xewkp5ydcDecpg73Jt834GrMijTRVrqBsYEewenZsbRzuKtFE5IOUArCh-kNiRNJ9pk Feb 18 05:48:04 volumio volumio[7954]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 05:48:04 volumio volumio[7954]: info: New Spotify access token = BQDDGnUgiqwsY9NpmOPSCBmCv3lpjEiYLsxX2_I4gliBps9MTtKuLamn3jIct3guFJbqwRBV6pp7kRd-wB89Vpfg4db5ekRK52Kgfl-gyfFZfOnZfHhkP53xe1rG_mVF_OdWwiMcgsQTSioPoOeblHVA923DsmyjpWmDlh-ejLugys5YeHXYEJ_fFRhrkNjRWnz1UP-SY-3s8zrP6_KGCRrlxhNG8hvHpBLMNDsdCnT08lt3oAiM0xewkp5ydcDecpg73Jt834GrMijTRVrqBsYEewenZsbRzuKtFE5IOUArCh-kNiRNJ9pk Feb 18 05:48:04 volumio volumio[7954]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 05:48:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 05:48:04 volumio sudo[8234]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:04 volumio sudo[8229]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:04 volumio sudo[8231]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:04 volumio volumio[7954]: info: Shairport-Sync Started Feb 18 05:48:04 volumio volumio[7954]: Error adding Membership: Error: addMembership EINVAL Feb 18 05:48:04 volumio volumio[7954]: info: Shairport-Sync Started Feb 18 05:48:04 volumio volumio[7954]: info: Shairport-Sync Started Feb 18 05:48:04 volumio volumio[7954]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:04 volumio volumio[7954]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:04 volumio volumio[7954]: 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 18 05:48:04 volumio volumio[7954]: info: Spotify Successfully logged in Feb 18 05:48:04 volumio volumio[7954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:04 volumio volumio[7954]: info: [1771368484854] CoreMusicLibrary::Adding element Spotify Feb 18 05:48:04 volumio volumio[7954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:04 volumio volumio[7954]: Cannot find translation for source YouTube Music Feb 18 05:48:04 volumio volumio[7954]: Cannot find translation for source Spotify Feb 18 05:48:05 volumio volumio[7954]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 05:48:05 volumio volumio[7954]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:48:05 volumio volumio[7954]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:48:05 volumio volumio[7954]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:05 volumio volumio[7954]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:05 volumio volumio[7954]: info: CoreStateMachine::pushState Feb 18 05:48:05 volumio volumio[7954]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:05 volumio volumio[7954]: info: CoreCommandRouter::volumioPushState Feb 18 05:48:06 volumio volumio[7954]: info: go-librespot daemon successfully initialized Feb 18 05:48:07 volumio mpd[8180]: 2026-02-18T05:48:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 05:48:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 05:48:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 05:48:07 volumio sudo[8150]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:07 volumio sudo[8140]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:07 volumio go-librespot[8271]: go-librespot daemon starting... Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=debug msg="app state loaded" Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:07 volumio volumio[7954]: error: MPD error: The expression evaluated to a falsy value: Feb 18 05:48:07 volumio volumio[7954]: assert.ok(self.idling) Feb 18 05:48:07 volumio volumio[7954]: error: The expression evaluated to a falsy value: Feb 18 05:48:07 volumio volumio[7954]: assert.ok(self.idling) Feb 18 05:48:07 volumio volumio[7954]: info: MPD running with PID8180 Feb 18 05:48:07 volumio volumio[7954]: ,establishing connection Feb 18 05:48:07 volumio volumio[7954]: error: updateQueue error: null Feb 18 05:48:07 volumio volumio[7954]: info: Completed starting Core Plugins Feb 18 05:48:07 volumio volumio[7954]: info: ------------------------------------------- Feb 18 05:48:07 volumio volumio[7954]: info: ----- MyVolumio plugins startup ---- Feb 18 05:48:07 volumio volumio[7954]: info: ------------------------------------------- Feb 18 05:48:07 volumio volumio[7954]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 05:48:07 volumio volumio[7954]: error: updateQueue error: null Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 05:48:07 volumio go-librespot[8274]: time="2026-02-18T05:48:07+07:00" level=info msg="zeroconf server listening on port 39607" Feb 18 05:48:08 volumio go-librespot[8274]: time="2026-02-18T05:48:08+07:00" level=debug msg="obtained new client token: AAD8utEEMVQXnIb9TKjlB5ZB+YJeYA9UFCmEC4aUcHzvlLhgDubD2BsTKUn2YVTgiRtu7dVr/VEqPn1nvEbgKDxKToZcEB8Yn0vbsgld9j79kII63vvuWytdhqryrd8DV5nk5bF9tfSSXWMWvsPKdeFRZzRTvQ+F1oYAxwZGGwTYJ7Lv/+37uTekNXqoyFFexpjsS36q8SUM5wbroq6sbXP3N/EnLEE3Zizr0oZvRdKDDENkcFLiSh4=" Feb 18 05:48:08 volumio go-librespot[8274]: time="2026-02-18T05:48:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:08 volumio go-librespot[8274]: time="2026-02-18T05:48:08+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:08 volumio go-librespot[8274]: time="2026-02-18T05:48:08+07:00" level=debug msg="completed challenge" Feb 18 05:48:08 volumio go-librespot[8274]: time="2026-02-18T05:48:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:09 volumio volumio[7954]: info: Initializing connection to go-librespot Websocket Feb 18 05:48:09 volumio volumio[7954]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:48:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 05:48:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:11 volumio go-librespot[8281]: go-librespot daemon starting... Feb 18 05:48:11 volumio go-librespot[8282]: time="2026-02-18T05:48:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:11 volumio go-librespot[8282]: time="2026-02-18T05:48:11+07:00" level=debug msg="app state loaded" Feb 18 05:48:11 volumio go-librespot[8282]: time="2026-02-18T05:48:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+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 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+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 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+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 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=info msg="zeroconf server listening on port 39799" Feb 18 05:48:12 volumio volumio[7954]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=debug msg="obtained new client token: AAAp7TldRaaDMBnOcRRJp0wwLGQF3kbC5iBZrCmF5FWMk2C6r9uDs5ovDw1fQozweWRFfF5dwdbd0/Dd2+tlitd6JZPjj11yi9VjkJvZPFEuKq5kfxHQ/HVmXTXz6sym/Jusj0irCIHP6TTKi17CQy4x7NcFqIyqrt4c5b4ZGyc5JsB35+mzz8w/5jCFfX1ijKGJ1zYWlu1FYXhrtGm+mLcMrFiCvyV0jChaW7Fj3P/ej8ULtMZqSX+xnA==" Feb 18 05:48:12 volumio volumio[7954]: info: Initializing connection to go-librespot Websocket Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=debug msg="new websocket client" Feb 18 05:48:12 volumio volumio[7954]: info: Connection to go-librespot Websocket established Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=debug msg="completed challenge" Feb 18 05:48:12 volumio go-librespot[8282]: time="2026-02-18T05:48:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:12 volumio volumio[7954]: info: Connection to go-librespot Websocket closed Feb 18 05:48:15 volumio volumio[7954]: info: Getting Spotify volume Feb 18 05:48:15 volumio volumio[7954]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 05:48:15 volumio volumio[7954]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:48:15 volumio volumio[7954]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 05:48:15 volumio volumio[7954]: errno: -111, Feb 18 05:48:15 volumio volumio[7954]: code: 'ECONNREFUSED', Feb 18 05:48:15 volumio volumio[7954]: syscall: 'connect', Feb 18 05:48:15 volumio volumio[7954]: address: '127.0.0.1', Feb 18 05:48:15 volumio volumio[7954]: port: 9879, Feb 18 05:48:15 volumio volumio[7954]: response: undefined Feb 18 05:48:15 volumio volumio[7954]: } Feb 18 05:48:15 volumio volumio[7954]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 05:48:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 05:48:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:15 volumio go-librespot[8305]: go-librespot daemon starting... Feb 18 05:48:15 volumio go-librespot[8306]: time="2026-02-18T05:48:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:15 volumio go-librespot[8306]: time="2026-02-18T05:48:15+07:00" level=debug msg="app state loaded" Feb 18 05:48:15 volumio go-librespot[8306]: time="2026-02-18T05:48:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=info msg="zeroconf server listening on port 36477" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="obtained new client token: AADt9YCN1a/5IgE/eESyVnGGcLOi9qdiC04L84ka3XlZri80N5GdoQEqTULAOf6t9Oo+pcUI1QrFHT+T5+etDNZwk/3hA0RqJIQAV7NUGZ3Y1K0yuESGdZqqpUyXEuax9Kg+sb2zMf0IqEEdBfHjWS4hPxCJ67hbLCjP1dnTSYXT1cC626ax+CyYbyypwSpvHk+IFJ3XKiAfI2OjRYaUwBJiFpRuy3uDQ10R6n3ayv5WMgzmX7DtJ8REIg==" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+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 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=debug msg="completed challenge" Feb 18 05:48:16 volumio go-librespot[8306]: time="2026-02-18T05:48:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:17 volumio sudo[8329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 05:47' Feb 18 05:48:17 volumio sudo[8329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:17 volumio sudo[8329]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:17 volumio volumio-remote-updater[25144]: [2026-02-18 05:48:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 05:48:17 volumio volumio-remote-updater[25144]: [2026-02-18 05:48:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 05:48:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:17 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 05:48:17 volumio systemd[1]: volumio.service: Consumed 49.232s CPU time. Feb 18 05:48:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 05:48:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 05:48:17 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21456. Feb 18 05:48:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 05:48:17 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 05:48:17 volumio systemd[1]: volumio.service: Consumed 49.232s CPU time. Feb 18 05:48:17 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 05:48:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 05:48:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 05:48:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:20 volumio go-librespot[8358]: go-librespot daemon starting... Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=debug msg="app state loaded" Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+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 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+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 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=info msg="zeroconf server listening on port 38981" Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=debug msg="obtained new client token: AAANpIUPu6MRz/ccSmxAS9qQO6fwDLdS2paD1HLqBlzmKEUhZrgtioTj9S9qPT7Gj47596eajGC6wk6iZMVZEs0FV5WGZ3m+mN7QHeR+RFZKwCQHEkjouEPlPKIIYW8Alg1ksZgNSjVXGN/Kba8PCnvvNCLoIOnLDaj2Z75RSsP27HrHpPMxwMRtBkFLhBd+S/K+B4oFfN8R6D7gqiuVqeRoBGFs2DoErLKsjU/1bGRPUC41vSAIgSjPTQ==" Feb 18 05:48:20 volumio go-librespot[8359]: time="2026-02-18T05:48:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:21 volumio go-librespot[8359]: time="2026-02-18T05:48:21+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:21 volumio go-librespot[8359]: time="2026-02-18T05:48:21+07:00" level=debug msg="completed challenge" Feb 18 05:48:21 volumio go-librespot[8359]: time="2026-02-18T05:48:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:21 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:21 volumio volumio[8343]: info: ----- Volumio3 ---- Feb 18 05:48:21 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:21 volumio volumio[8343]: info: ----- System startup ---- Feb 18 05:48:21 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:22 volumio volumio-remote-updater[25144]: [2026-02-18 05:48:22] [connect] Successful connection Feb 18 05:48:22 volumio volumio[8343]: info: MYVOLUMIO Environment detected Feb 18 05:48:22 volumio volumio[8343]: info: Plugin folders cleanup Feb 18 05:48:22 volumio volumio[8343]: info: Scanning into folder /volumio/app/plugins/ Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category audio_interface Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category miscellanea Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category music_service Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category plugins.json Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category system_controller Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category user_interface Feb 18 05:48:22 volumio volumio[8343]: info: Scanning into folder /data/plugins/ Feb 18 05:48:22 volumio volumio[8343]: info: Scanning category music_service Feb 18 05:48:22 volumio volumio[8343]: info: Plugin folders cleanup completed Feb 18 05:48:22 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:22 volumio volumio[8343]: info: ----- Core plugins startup ---- Feb 18 05:48:22 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:22 volumio volumio[8343]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 05:48:22 volumio volumio[8343]: info: Adding plugin upnp to MyMusic Plugins Feb 18 05:48:22 volumio volumio[8343]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 05:48:22 volumio volumio[8343]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 05:48:22 volumio volumio[8343]: info: Loading plugins from folder /data/plugins/ Feb 18 05:48:22 volumio volumio[8343]: info: Loading plugin "system"... Feb 18 05:48:22 volumio volumio[8343]: info: Loading plugin "appearance"... Feb 18 05:48:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 05:48:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:24 volumio go-librespot[8378]: go-librespot daemon starting... Feb 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48:24+07:00" level=debug msg="app state loaded" Feb 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:24 volumio volumio[8343]: info: Loading plugin "network"... Feb 18 05:48:24 volumio volumio[8343]: info: Refreshing Cached IP Addresses Feb 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48:24+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 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48:24+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 18 05:48:24 volumio sudo[8387]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 05:48:24 volumio go-librespot[8379]: time="2026-02-18T05:48:24+07:00" level=info msg="zeroconf server listening on port 42837" Feb 18 05:48:24 volumio sudo[8387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:24 volumio volumio[8343]: info: Loading plugin "services"... Feb 18 05:48:24 volumio sudo[8387]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "alsa_controller"... Feb 18 05:48:25 volumio sudo[8389]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 05:48:25 volumio sudo[8389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:25 volumio sudo[8389]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:25 volumio sudo[8396]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 05:48:25 volumio sudo[8396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:25 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "wizard"... Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "networkfs"... Feb 18 05:48:25 volumio go-librespot[8379]: time="2026-02-18T05:48:25+07:00" level=debug msg="obtained new client token: AAC9Xd7LmjHdCz1X75wLZ0eo3kQrd0JG+4WHpfuyV1JKhOa8xtIA33OVorigavNeFwiJOSF9Xcq8RgyxRr4ZJDQw5w6YZVDHrPbh7mFbtppGorX3FJA3EgqswkIJa6nepa0mPb3YC2rAQC8yXv0WAxWd4qOobkH/+b4UdclVzVlYhM9fWFE2NicKuLj0d0q9Q+vOjVqZiYDjQ79aRHX+8x0UokkCkGmJ0XtB/FlU0qGgDys6r38sgwY=" Feb 18 05:48:25 volumio volumio[8343]: info: Starting Udev Watcher for removable devices Feb 18 05:48:25 volumio volumio[8343]: info: Ignoring mount for partition: boot Feb 18 05:48:25 volumio volumio[8343]: info: Ignoring mount for partition: volumio Feb 18 05:48:25 volumio volumio[8343]: info: Ignoring mount for partition: volumio_data Feb 18 05:48:25 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "volumio_command_line_client"... Feb 18 05:48:25 volumio go-librespot[8379]: time="2026-02-18T05:48:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "upnp"... Feb 18 05:48:25 volumio volumio[8343]: info: [1771368505339] Starting Upmpd Daemon Feb 18 05:48:25 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "my_music"... Feb 18 05:48:25 volumio volumio[8343]: info: Loading plugin "mpd"... Feb 18 05:48:25 volumio go-librespot[8379]: time="2026-02-18T05:48:25+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:25 volumio go-librespot[8379]: time="2026-02-18T05:48:25+07:00" level=debug msg="completed challenge" Feb 18 05:48:25 volumio go-librespot[8379]: time="2026-02-18T05:48: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 18 05:48:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:26 volumio volumio[8343]: info: Loading plugin "upnp_browser"... Feb 18 05:48:27 volumio sudo[8396]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 18 05:48:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:28 volumio go-librespot[8420]: go-librespot daemon starting... Feb 18 05:48:28 volumio go-librespot[8421]: time="2026-02-18T05:48:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:28 volumio go-librespot[8421]: time="2026-02-18T05:48:28+07:00" level=debug msg="app state loaded" Feb 18 05:48:28 volumio go-librespot[8421]: time="2026-02-18T05:48:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:28 volumio volumio[8343]: info: Starting UPNP Browser Feb 18 05:48:28 volumio volumio[8343]: info: Loading plugin "alarm-clock"... Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+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 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+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 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=info msg="zeroconf server listening on port 39739" Feb 18 05:48:29 volumio volumio[8343]: info: Loading plugin "airplay_emulation"... Feb 18 05:48:29 volumio volumio[8343]: info: Starting Shairport Sync Feb 18 05:48:29 volumio volumio[8343]: info: Loading plugin "last_100"... Feb 18 05:48:29 volumio volumio[8343]: info: Loading plugin "webradio"... Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=debug msg="obtained new client token: AABv1AJYjr+CC/PBhFsTSM7tCQT11Rk0D0x6IxsAsoCWGPhoBCu/xj+qoOLQZ6ezWWO0HXpZlG/trvZYu0v2ES17dD8tkTtn6sPqAjKSr1ORb23ArvGqIW8iQpNmfzElUDtHrAnDfF0/9gWsXzqaO6A1rB8q5vi9JuFGhV3aM9hyF9jlaxQ18Gi8Ynvv/xA9u5d7ewXMLYYYSbtx5X9mDnLO/VCqDECOMOJWc0lppDvEDIN6uyHaG2ivqg==" Feb 18 05:48:29 volumio volumio[8343]: info: Loading plugin "i2s_dacs"... Feb 18 05:48:29 volumio volumio[8343]: info: Loading plugin "volumiodiscovery"... Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:29 volumio volumio[8343]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 05:48:29 volumio volumio[8343]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:48:29 volumio volumio[8343]: *** WARNING *** For more information see Feb 18 05:48:29 volumio volumio[8343]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 05:48:29 volumio volumio[8343]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:48:29 volumio volumio[8343]: *** WARNING *** For more information see Feb 18 05:48:29 volumio node[8343]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 05:48:29 volumio node[8343]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:48:29 volumio node[8343]: *** WARNING *** For more information see Feb 18 05:48:29 volumio node[8343]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 05:48:29 volumio node[8343]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:48:29 volumio node[8343]: *** WARNING *** For more information see Feb 18 05:48:29 volumio volumio[8343]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 05:48:29 volumio volumio[8343]: info: Discovery: Started advertising with name: Volumio Feb 18 05:48:29 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 05:48:29 volumio volumio[8343]: info: Loading plugin "spop"... Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=debug msg="completed challenge" Feb 18 05:48:29 volumio go-librespot[8421]: time="2026-02-18T05:48:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:31 volumio volumio[8343]: info: Loading plugin "ytcr"... Feb 18 05:48:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 18 05:48:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:32 volumio go-librespot[8431]: go-librespot daemon starting... Feb 18 05:48:32 volumio go-librespot[8432]: time="2026-02-18T05:48:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:32 volumio go-librespot[8432]: time="2026-02-18T05:48:32+07:00" level=debug msg="app state loaded" Feb 18 05:48:32 volumio go-librespot[8432]: time="2026-02-18T05:48:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+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 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+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 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+07:00" level=info msg="zeroconf server listening on port 35493" Feb 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+07:00" level=debug msg="obtained new client token: AAC7yfOZF39GNYFgQY3ABhl7hIv0NCqSOrD4tZTB09wyJXAijeytSESPASeDg8vMwjNpo0ggv0JQbi955ySbVwdn8Uvncg4uK1cUtr61fI5ztn8nLeWP9ewpsEspDxPkrpgkb5hBVkBxBCuEjBLgUfglb9vJNOcToHFJO/IFC/e8ComS8QM0MuTRii0saMq1jw9TrPT4/61JLXukdlyDw59EoFYFl3Zg23D6O17Fg6QU20qBLGSXIV2cIQ==" Feb 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:33 volumio go-librespot[8432]: time="2026-02-18T05:48:33+07:00" level=debug msg="completed challenge" Feb 18 05:48:34 volumio go-librespot[8432]: time="2026-02-18T05:48:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:34 volumio volumio[8343]: info: Loading plugin "ytmusic"... Feb 18 05:48:35 volumio volumio-remote-updater[25144]: [2026-02-18 05:48:35] [connect] Successful connection Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "outputs"... Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "albumart"... Feb 18 05:48:35 volumio volumio[8343]: info: Plugin example_plugin is not enabled Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "inputs"... Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "updater_comm"... Feb 18 05:48:35 volumio volumio[8343]: info: Plugin mpdemulation is not enabled Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "rest_api"... Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "websocket"... Feb 18 05:48:35 volumio volumio[8343]: info: Starting Socket.io Server version 1.7.4 Feb 18 05:48:35 volumio volumio[8343]: info: Loading plugin "RoonBridge"... Feb 18 05:48:36 volumio volumio[8343]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 05:48:36 volumio volumio[8343]: info: Loading i18n strings for locale en Feb 18 05:48:36 volumio volumio[8343]: Updating browse sources language Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:36 volumio volumio[8453]: Forking 3 albumart workers Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::initPlayerControls Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 05:48:36 volumio volumio[8343]: Express server listening on port 3000 Feb 18 05:48:36 volumio volumio[8343]: [Metrics] WebUI: 16s 80.70ms Feb 18 05:48:36 volumio volumio[8343]: info: CoreStateMachine::resetVolumioState Feb 18 05:48:36 volumio volumio[8343]: info: CoreStateMachine::getcurrentVolume Feb 18 05:48:36 volumio volumio[8343]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:48:36 volumio sudo[8495]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 05:48:36 volumio sudo[8495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:36 volumio sudo[8498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 05:48:36 volumio sudo[8498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:36 volumio sudo[8495]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:36 volumio sudo[8498]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:36 volumio volumio[8343]: info: Volumio Network Manager: Network status updated: 1 Feb 18 05:48:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 18 05:48:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:37 volumio volumio[8343]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::pushState Feb 18 05:48:37 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::volumioPushState Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::updateTrackBlock Feb 18 05:48:37 volumio volumio[8343]: info: CorePlayQueue::getTrackBlock Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:48:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:37 volumio go-librespot[8504]: go-librespot daemon starting... Feb 18 05:48:37 volumio volumio-remote-updater[25144]: [2026-02-18 05:48:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771368515 101 Feb 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+07:00" level=debug msg="app state loaded" Feb 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:37 volumio volumio[8343]: 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 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:37 volumio volumio[8343]: info: Reloading queue from file Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::setRepeat null single undefined Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::pushState Feb 18 05:48:37 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::volumioPushState Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::setRandom null Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::pushState Feb 18 05:48:37 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::volumioPushState Feb 18 05:48:37 volumio volumio[8343]: info: Setting Device type: Raspberry PI Feb 18 05:48:37 volumio volumio[8343]: info: Completed loading Core Plugins Feb 18 05:48:37 volumio volumio[8343]: info: Preparing to generate the ALSA configuration file Feb 18 05:48:37 volumio volumio[8343]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:48:37 volumio volumio[8343]: info: CoreStateMachine::pushState Feb 18 05:48:37 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::volumioPushState Feb 18 05:48:37 volumio volumio[8343]: info: Asound.conf file unchanged, so no further update is needed Feb 18 05:48:37 volumio volumio[8343]: info: Output device has changed, restarting MPD Feb 18 05:48:37 volumio sudo[8522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 05:48:37 volumio sudo[8522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:37 volumio volumio[8343]: info: Output device has changed, restarting Shairport Sync Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:37 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+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 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+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 18 05:48:37 volumio sudo[8525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 05:48:37 volumio go-librespot[8506]: time="2026-02-18T05:48:37+07:00" level=info msg="zeroconf server listening on port 42121" Feb 18 05:48:37 volumio sudo[8525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:37 volumio sudo[8525]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:37 volumio sudo[8527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 05:48:37 volumio sudo[8527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:37 volumio sudo[8522]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:37 volumio volumio[8343]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 05:48:37 volumio volumio[8343]: info: ___________ START PLUGINS ___________ Feb 18 05:48:38 volumio volumio[8343]: info: ControllerMpd::onStart: Initializing MPD Feb 18 05:48:38 volumio volumio[8343]: info: Creating MPD Configuration file Feb 18 05:48:38 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 05:48:38 volumio go-librespot[8506]: time="2026-02-18T05:48:38+07:00" level=debug msg="obtained new client token: AAAgaECkbMAjQv9eLIMnFYmE8IQSYxf3JQb0ooMZJQohCtUgVNzauWLQhcCa/a1134/pxPjd0ncusOiowAFmXco0FU+bNoW3VDDwQSt9/TkLjXxYi87obSuYH2mPepwmk7JmZTydE0kXhPwYwAjouvjB+wWqoezMaz5m2psePIkp+gvjQAoHvy0h4Cygu/2XdqLBVIn+70SlJv75joXHvVc1g+F/GxroP9UONYBpTEPAK3IohQg0Li8=" Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:38 volumio volumio[8343]: info: [1771368518133] CoreMusicLibrary::Adding element Media Servers Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:38 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 05:48:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 05:48:38 volumio systemd[1]: mpd.service: Consumed 7.128s CPU time. Feb 18 05:48:38 volumio volumio[8343]: info: UPNP Browser: Client initialized successfully Feb 18 05:48:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 05:48:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 05:48:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 05:48:38 volumio go-librespot[8506]: time="2026-02-18T05:48:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:38 volumio sudo[8535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 05:48:38 volumio sudo[8535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:38 volumio sudo[8537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 05:48:38 volumio sudo[8535]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:38 volumio sudo[8537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 05:48:38 volumio go-librespot[8506]: time="2026-02-18T05:48:38+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:38 volumio go-librespot[8506]: time="2026-02-18T05:48:38+07:00" level=debug msg="completed challenge" Feb 18 05:48:38 volumio volumio[8343]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:38 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 05:48:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 05:48:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 05:48:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 05:48:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 05:48:38 volumio volumio[8343]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:38 volumio volumio[8343]: info: [1771368518508] CoreMusicLibrary::Adding element Last_100 Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:38 volumio go-librespot[8506]: time="2026-02-18T05:48:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 05:48:38 volumio volumio[8343]: info: [1771368518528] CoreMusicLibrary::Adding element Webradio Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 05:48:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:48:38 volumio volumio[8343]: info: Initializing BBC Radios Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:38 volumio volumio[8343]: info: Creating Spotify config file Feb 18 05:48:38 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:39 volumio sudo[8551]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 05:48:39 volumio sudo[8551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 05:48:39 volumio sudo[8551]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:39 volumio volumio[8464]: Starting albumart workers Feb 18 05:48:39 volumio volumio[8465]: Starting albumart workers Feb 18 05:48:40 volumio volumio[8343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:40 volumio volumio[8343]: info: [1771368520086] CoreMusicLibrary::Adding element YouTube Music Feb 18 05:48:40 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:40 volumio volumio[8343]: Cannot find translation for source YouTube Music Feb 18 05:48:40 volumio volumio[8463]: Starting albumart workers Feb 18 05:48:40 volumio volumio[8343]: info: Volumio Calling Home Feb 18 05:48:40 volumio sudo[8568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 05:48:40 volumio sudo[8568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:40 volumio sudo[8568]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:40 volumio volumio[8343]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 05:48:40 volumio volumio[8343]: info: Discovery: Found device Volumio Feb 18 05:48:40 volumio volumio[8343]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:40 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:41 volumio volumio[8343]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 05:48:41 volumio volumio[8343]: info: Discovery: Found device Volumio Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:41 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:41 volumio volumio[8343]: info: MPD Permissions set Feb 18 05:48:41 volumio volumio[8343]: info: MPD Permissions set Feb 18 05:48:41 volumio volumio[8343]: info: Upmpdcli Daemon Started Feb 18 05:48:41 volumio volumio[8343]: info: Volumio called home Feb 18 05:48:41 volumio volumio[8343]: info: Spotify config file written Feb 18 05:48:41 volumio sudo[8580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 05:48:41 volumio sudo[8580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:41 volumio volumio[8343]: 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 18 05:48:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:41 volumio go-librespot[8582]: go-librespot daemon starting... Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio sudo[8580]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:41 volumio go-librespot[8583]: time="2026-02-18T05:48:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:41 volumio go-librespot[8583]: time="2026-02-18T05:48:41+07:00" level=debug msg="app state loaded" Feb 18 05:48:41 volumio go-librespot[8583]: time="2026-02-18T05:48:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:48:41 volumio volumio[8343]: info: No need to fix Spotify hosts Feb 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48: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 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48: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 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48: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 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48:42+07:00" level=info msg="zeroconf server listening on port 33345" Feb 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48:42+07:00" level=debug msg="obtained new client token: AABj/C3GTSeeuNo3/gtX8kUFODvhnzio/OeSwqyhK1XJf0S0pwQmNwOSPdYP/34EX2SgfBfjJiEN+LQ4n+BgquCW8Ow1ywiYpYs/dlF+QYXVPi5a0I2TCuVP+T3tWmn564J47XUHZLn0qHZeaXE7fARoOcl4TijagE4B2cHVyu+R/ETgLd3GfdrQ4hYzlJ8tMW6fq6Wwca2n5/fGVwaLMMVStUgj1V25NFHTjKa0WMoRhmxUivEUYv3l+w==" Feb 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:42 volumio volumio[8343]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 05:48:42 volumio volumio[8343]: SPOTIFY: BQCADxO0H_rmt8CSZ85fN43IuHR2jE4Zg1kS52oSYHzBXG6FgJDiECCh0049UVI6kh9Umw0mw5fUCW9934bBGMUI1AGd_k6rQ0aid1FHKiE0ZoUJXVbbggwwTo5ta52v8_DrdXhjZSMwpXvBE70nhmMpugPo38Gv6Qqs3zgyOM8ESlvspMCclNjr7ZPHmrwIiFatfMy1QBw48Eg8eL8rWJgscjfx67yHUEV9cPJ0Orm3aWwef_b7ebkPegqu9i_UJYZPHqh_qC05H67ZzPAmDPW_pTQXr4w8ZTHYNMWUxe7d4O_eHu0visYb Feb 18 05:48:42 volumio volumio[8343]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 05:48:42 volumio volumio[8343]: info: New Spotify access token = BQCADxO0H_rmt8CSZ85fN43IuHR2jE4Zg1kS52oSYHzBXG6FgJDiECCh0049UVI6kh9Umw0mw5fUCW9934bBGMUI1AGd_k6rQ0aid1FHKiE0ZoUJXVbbggwwTo5ta52v8_DrdXhjZSMwpXvBE70nhmMpugPo38Gv6Qqs3zgyOM8ESlvspMCclNjr7ZPHmrwIiFatfMy1QBw48Eg8eL8rWJgscjfx67yHUEV9cPJ0Orm3aWwef_b7ebkPegqu9i_UJYZPHqh_qC05H67ZzPAmDPW_pTQXr4w8ZTHYNMWUxe7d4O_eHu0visYb Feb 18 05:48:42 volumio volumio[8343]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 05:48:42 volumio volumio[8343]: info: Starting Shairport Sync Feb 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48:42+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48:42+07:00" level=debug msg="completed challenge" Feb 18 05:48:42 volumio volumio[8343]: info: Starting Shairport Sync Feb 18 05:48:42 volumio volumio[8343]: info: Starting Shairport Sync Feb 18 05:48:42 volumio sudo[8613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:48:42 volumio sudo[8613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:42 volumio go-librespot[8583]: time="2026-02-18T05:48:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:42 volumio sudo[8615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:48:42 volumio sudo[8615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:42 volumio sudo[8617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:48:42 volumio sudo[8617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 05:48:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 05:48:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 05:48:43 volumio systemd[1]: shairport-sync.service: Consumed 2.199s CPU time. Feb 18 05:48:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 05:48:43 volumio sudo[8617]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:43 volumio sudo[8613]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:43 volumio sudo[8615]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:43 volumio volumio[8343]: info: Shairport-Sync Started Feb 18 05:48:43 volumio volumio[8343]: Error adding Membership: Error: addMembership EINVAL Feb 18 05:48:43 volumio volumio[8343]: info: Shairport-Sync Started Feb 18 05:48:43 volumio volumio[8343]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:43 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:43 volumio volumio[8343]: info: Shairport-Sync Started Feb 18 05:48:43 volumio volumio[8343]: 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 18 05:48:43 volumio volumio[8343]: info: Spotify Successfully logged in Feb 18 05:48:43 volumio volumio[8343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:48:43 volumio volumio[8343]: info: [1771368523516] CoreMusicLibrary::Adding element Spotify Feb 18 05:48:43 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:48:43 volumio volumio[8343]: Cannot find translation for source YouTube Music Feb 18 05:48:43 volumio volumio[8343]: Cannot find translation for source Spotify Feb 18 05:48:44 volumio volumio[8343]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 05:48:44 volumio volumio[8343]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:48:44 volumio volumio[8343]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:48:44 volumio volumio[8343]: info: CoreCommandRouter::volumioGetState Feb 18 05:48:44 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:44 volumio volumio[8343]: info: CoreStateMachine::pushState Feb 18 05:48:44 volumio volumio[8343]: info: CorePlayQueue::getTrack 0 Feb 18 05:48:44 volumio volumio[8343]: info: CoreCommandRouter::volumioPushState Feb 18 05:48:45 volumio volumio[8343]: info: go-librespot daemon successfully initialized Feb 18 05:48:45 volumio mpd[8566]: 2026-02-18T05:48:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 05:48:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 05:48:45 volumio sudo[8537]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:45 volumio sudo[8527]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 18 05:48:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:45 volumio go-librespot[8657]: go-librespot daemon starting... Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=debug msg="app state loaded" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:46 volumio volumio[8343]: error: MPD error: The expression evaluated to a falsy value: Feb 18 05:48:46 volumio volumio[8343]: assert.ok(self.idling) Feb 18 05:48:46 volumio volumio[8343]: error: The expression evaluated to a falsy value: Feb 18 05:48:46 volumio volumio[8343]: assert.ok(self.idling) Feb 18 05:48:46 volumio volumio[8343]: error: updateQueue error: null Feb 18 05:48:46 volumio volumio[8343]: info: MPD running with PID8566 Feb 18 05:48:46 volumio volumio[8343]: ,establishing connection Feb 18 05:48:46 volumio volumio[8343]: info: Completed starting Core Plugins Feb 18 05:48:46 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:46 volumio volumio[8343]: info: ----- MyVolumio plugins startup ---- Feb 18 05:48:46 volumio volumio[8343]: info: ------------------------------------------- Feb 18 05:48:46 volumio volumio[8343]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 05:48:46 volumio volumio[8343]: error: updateQueue error: null Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+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 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+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 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=info msg="zeroconf server listening on port 33671" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=debug msg="obtained new client token: AACXgTVK5Yp2PgfCLOfeHVUKOW3iyzTU9DNyNchosdGb+h7p6BMojFhQakIgwSBc4GyunmHjbzbiCIMghyYMQ+7iHFV1ghL+Ov+zCWbPOs1V/lusy3SEiF0eC0qosyhqTgmVDyN8duB4ai2rqRimkVgfCXt2DSv29YJbVE+upcbJ4I9S5JN6iqzXLxwA22TsVo3oEqpIYZjAfxQUnJZxIhk0CfUkw5y08UX5rITqeXMJPT6lOYpPySdBGA==" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:46 volumio go-librespot[8658]: time="2026-02-18T05:48:46+07:00" level=debug msg="completed challenge" Feb 18 05:48:47 volumio go-librespot[8658]: time="2026-02-18T05:48:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:48 volumio volumio[8343]: info: Initializing connection to go-librespot Websocket Feb 18 05:48:48 volumio volumio[8343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:48:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 18 05:48:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:50 volumio go-librespot[8665]: go-librespot daemon starting... Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=debug msg="app state loaded" Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+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 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+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 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=info msg="zeroconf server listening on port 36913" Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=debug msg="obtained new client token: AADpAP5hJnJxJyKhdqZsj+RY9U3oP4N1/mNLRm5XUO7iMX9ksk2Q8k9xoWliqWJ3gJiJQmlO+CRl+Kuo3IM5Sj29BzQUQoh0WSpBr/Bt/gUyoMdwSxWVO/Jq+bnfktYQQpdo3UjxktWCqVlI5/9GOo9ovx09XajK4QJmLQaEye+usa2xdNTdnPhkeUabM837YDT+3Qai9am64VMktZkdJ31q8RckemMp0DcWQ4EGeyDS1JS/fWxqkgUYKA==" Feb 18 05:48:50 volumio volumio[8343]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 05:48:50 volumio go-librespot[8666]: time="2026-02-18T05:48:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:51 volumio go-librespot[8666]: time="2026-02-18T05:48:51+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:51 volumio go-librespot[8666]: time="2026-02-18T05:48:51+07:00" level=debug msg="completed challenge" Feb 18 05:48:51 volumio go-librespot[8666]: time="2026-02-18T05:48:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:51 volumio volumio[8343]: info: Initializing connection to go-librespot Websocket Feb 18 05:48:51 volumio volumio[8343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:48:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 18 05:48:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:54 volumio go-librespot[8674]: go-librespot daemon starting... Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=debug msg="app state loaded" Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:54 volumio volumio[8343]: info: Initializing connection to go-librespot Websocket Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=debug msg="new websocket client" Feb 18 05:48:54 volumio volumio[8343]: info: Connection to go-librespot Websocket established Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 05:48:54 volumio go-librespot[8675]: time="2026-02-18T05:48:54+07:00" level=info msg="zeroconf server listening on port 38227" Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 05:48:55 volumio volumio[8343]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+07:00" level=debug msg="obtained new client token: AABh2KhqOUGMhCCUj4Kdfg894sMBRq+vUkao4+JOtqyB1Sa8ezZNzqHzP3gIsuLtlreSYxlYb5OIY5WXw6Wx7Aucj3J/os6N6yLyg/Qnv5yxEZ9frH78WGNBx3Pod/9JGPhj6dMDOVC62Th7eCKoVA979Hy+dUB1BCgN4FGWLqUstOoHjReyqB4rojzcgVFQ0DpYG7CKJEcmtWMFyVmO6qsJFhI+RcijcEtX/fPXtOYs/QD6JxFVLiQ=" Feb 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+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 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+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 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+07:00" level=debug msg="completed challenge" Feb 18 05:48:55 volumio go-librespot[8675]: time="2026-02-18T05:48:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:48:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:48:56 volumio volumio[8343]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 05:48:56 volumio volumio[8343]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 05:48:56 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:56 volumio volumio[8343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:48:56 volumio volumio[8343]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 05:48:56 volumio volumio[8343]: info: MyVolumio login type: Token Feb 18 05:48:56 volumio volumio[8343]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 05:48:56 volumio volumio[8343]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 05:48:58 volumio volumio[8343]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 05:48:58 volumio volumio[8343]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 05:48:58 volumio volumio[8343]: info: Streaming services startup Feb 18 05:48:58 volumio volumio[8343]: info: Starting Streaming Daemon Feb 18 05:48:58 volumio sudo[8697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 05:48:58 volumio sudo[8697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:48:58 volumio volumio[8343]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 05:48:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 18 05:48:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:48:58 volumio go-librespot[8703]: go-librespot daemon starting... Feb 18 05:48:58 volumio volumio[8343]: info: Getting Spotify volume Feb 18 05:48:58 volumio sudo[8697]: pam_unix(sudo:session): session closed for user root Feb 18 05:48:58 volumio volumio[8343]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 05:48:58 volumio go-librespot[8704]: time="2026-02-18T05:48:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:48:58 volumio go-librespot[8704]: time="2026-02-18T05:48:58+07:00" level=debug msg="app state loaded" Feb 18 05:48:58 volumio go-librespot[8704]: time="2026-02-18T05:48:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:48:58 volumio volumio[8343]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:48:58 volumio volumio[8343]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 05:48:58 volumio volumio[8343]: errno: -111, Feb 18 05:48:58 volumio volumio[8343]: code: 'ECONNREFUSED', Feb 18 05:48:58 volumio volumio[8343]: syscall: 'connect', Feb 18 05:48:58 volumio volumio[8343]: address: '127.0.0.1', Feb 18 05:48:58 volumio volumio[8343]: port: 9879, Feb 18 05:48:58 volumio volumio[8343]: response: undefined Feb 18 05:48:58 volumio volumio[8343]: } Feb 18 05:48:58 volumio volumio[8343]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=info msg="zeroconf server listening on port 39255" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="obtained new client token: AACpustdRguDdNzrDudt8vry2HlTuo9RJGdeVzUa503MVI3oWaeoQDt+R7rFbWYhOTE26IiOniMFUGK8o8JAeWIuEA2ASsy82tdwhoWa5FZ3nM9ovsq1H2re7FC2/T7sIXU9WN+JuTifd3ENNNqtqNqPONxi9KuATPPjbW8IDbZ0m2IPgJGw3onRRzwQR04AXqrBZZ1qc1hftm/c/gY4Tyty0j6LHixpzIkf5WZCVBaHP9962QBYMvUtFg==" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="completed keyexchange" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+07:00" level=debug msg="completed challenge" Feb 18 05:48:59 volumio go-librespot[8704]: time="2026-02-18T05:48:59+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 18 05:48:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:48:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:00 volumio sudo[8726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 05:48' Feb 18 05:49:00 volumio sudo[8726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:00 volumio sudo[8726]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:00 volumio volumio-remote-updater[25144]: [2026-02-18 05:49:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 05:49:00 volumio volumio-remote-updater[25144]: [2026-02-18 05:49:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 05:49:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 05:49:00 volumio systemd[1]: volumio.service: Consumed 54.900s CPU time. Feb 18 05:49:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 05:49:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 05:49:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21457. Feb 18 05:49:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 05:49:00 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 05:49:00 volumio systemd[1]: volumio.service: Consumed 54.900s CPU time. Feb 18 05:49:00 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 05:49:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 05:49:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 18 05:49:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:03 volumio go-librespot[8753]: go-librespot daemon starting... Feb 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+07:00" level=debug msg="app state loaded" Feb 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+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 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+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 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+07:00" level=info msg="zeroconf server listening on port 40377" Feb 18 05:49:03 volumio go-librespot[8754]: time="2026-02-18T05:49:03+07:00" level=debug msg="obtained new client token: AACBnJh+yPJR3eWfWBJXroYcj3SkoHFbWYOxYHyyU6ZoJYUizH+CXa3h31hn5tFcN5Pit1q7FzpRHQgdjVJufSYgR7N7Ji0zgShdhSyuX5u5WKcD6AqJ1lpmsypmYyUKJXBo0fSf3Bllpn6gCDSpOKEa67/+Mf1HcGhER4pECbyh4kUDQU4VLE9Lzf1BSY9sEyhYyYm8/O1t/ViAgyqVGR8E3BDgYfd2v8Oi+009h3l/Ov+bh/2Xz8lHAQ==" Feb 18 05:49:04 volumio go-librespot[8754]: time="2026-02-18T05:49:04+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 18 05:49:04 volumio go-librespot[8754]: time="2026-02-18T05:49:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 05:49:04 volumio go-librespot[8754]: time="2026-02-18T05:49:04+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:04 volumio go-librespot[8754]: time="2026-02-18T05:49:04+07:00" level=debug msg="completed challenge" Feb 18 05:49:04 volumio go-librespot[8754]: time="2026-02-18T05:49:04+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 18 05:49:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:04 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:04 volumio volumio[8738]: info: ----- Volumio3 ---- Feb 18 05:49:04 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:04 volumio volumio[8738]: info: ----- System startup ---- Feb 18 05:49:04 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:05 volumio volumio-remote-updater[25144]: [2026-02-18 05:49:05] [connect] Successful connection Feb 18 05:49:06 volumio volumio[8738]: info: MYVOLUMIO Environment detected Feb 18 05:49:06 volumio volumio[8738]: info: Plugin folders cleanup Feb 18 05:49:06 volumio volumio[8738]: info: Scanning into folder /volumio/app/plugins/ Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category audio_interface Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category miscellanea Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category music_service Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category plugins.json Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category system_controller Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category user_interface Feb 18 05:49:06 volumio volumio[8738]: info: Scanning into folder /data/plugins/ Feb 18 05:49:06 volumio volumio[8738]: info: Scanning category music_service Feb 18 05:49:06 volumio volumio[8738]: info: Plugin folders cleanup completed Feb 18 05:49:06 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:06 volumio volumio[8738]: info: ----- Core plugins startup ---- Feb 18 05:49:06 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:06 volumio volumio[8738]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 05:49:06 volumio volumio[8738]: info: Adding plugin upnp to MyMusic Plugins Feb 18 05:49:06 volumio volumio[8738]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 05:49:06 volumio volumio[8738]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 05:49:06 volumio volumio[8738]: info: Loading plugins from folder /data/plugins/ Feb 18 05:49:06 volumio volumio[8738]: info: Loading plugin "system"... Feb 18 05:49:06 volumio volumio[8738]: info: Loading plugin "appearance"... Feb 18 05:49:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 18 05:49:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:07 volumio go-librespot[8773]: go-librespot daemon starting... Feb 18 05:49:07 volumio go-librespot[8774]: time="2026-02-18T05:49:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:07 volumio go-librespot[8774]: time="2026-02-18T05:49:07+07:00" level=debug msg="app state loaded" Feb 18 05:49:07 volumio go-librespot[8774]: time="2026-02-18T05:49:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "network"... Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+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 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+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 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+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 18 05:49:08 volumio volumio[8738]: info: Refreshing Cached IP Addresses Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+07:00" level=info msg="zeroconf server listening on port 38811" Feb 18 05:49:08 volumio sudo[8782]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 05:49:08 volumio sudo[8782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:08 volumio sudo[8784]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 05:49:08 volumio sudo[8784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:08 volumio sudo[8782]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:08 volumio sudo[8784]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "services"... Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "alsa_controller"... Feb 18 05:49:08 volumio sudo[8797]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 05:49:08 volumio sudo[8797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:08 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "wizard"... Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "networkfs"... Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+07:00" level=debug msg="obtained new client token: AADZaMemN8V2snhcg41gUHj5atJIcCzj8NGp069Z/V5vrY1dPaNXBHGgp2YhJx1Rc8NrnM41rHoOupTUHGblm+xz/yy0nrZbg+gw5DKbu7J6Bu48Fh+B/L1XUfexWgSBQQ1BliqPf2JNOscXGOMFR0fdPxtIGwWuvLjgG/mT8Hfl++OSVqwxaUxYpZZW00x1t8uAVQ12Y+zeXav4w8iuNn2peEEJS8i3K4JzkD4CgEuzeD/IhIiPSrtYvA==" Feb 18 05:49:08 volumio volumio[8738]: info: Starting Udev Watcher for removable devices Feb 18 05:49:08 volumio volumio[8738]: info: Ignoring mount for partition: boot Feb 18 05:49:08 volumio volumio[8738]: info: Ignoring mount for partition: volumio Feb 18 05:49:08 volumio volumio[8738]: info: Ignoring mount for partition: volumio_data Feb 18 05:49:08 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "volumio_command_line_client"... Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "upnp"... Feb 18 05:49:08 volumio volumio[8738]: info: [1771368548676] Starting Upmpd Daemon Feb 18 05:49:08 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "my_music"... Feb 18 05:49:08 volumio volumio[8738]: info: Loading plugin "mpd"... Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+07:00" level=debug msg="completed challenge" Feb 18 05:49:08 volumio go-librespot[8774]: time="2026-02-18T05:49:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:49:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:09 volumio volumio[8738]: info: Loading plugin "upnp_browser"... Feb 18 05:49:11 volumio sudo[8797]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 18 05:49:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:12 volumio go-librespot[8815]: go-librespot daemon starting... Feb 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+07:00" level=debug msg="app state loaded" Feb 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:12 volumio volumio[8738]: info: Starting UPNP Browser Feb 18 05:49:12 volumio volumio[8738]: info: Loading plugin "alarm-clock"... Feb 18 05:49:12 volumio volumio[8738]: info: Loading plugin "airplay_emulation"... Feb 18 05:49:12 volumio volumio[8738]: info: Starting Shairport Sync Feb 18 05:49:12 volumio volumio[8738]: info: Loading plugin "last_100"... Feb 18 05:49:12 volumio volumio[8738]: info: Loading plugin "webradio"... Feb 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+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 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+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 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+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 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+07:00" level=info msg="zeroconf server listening on port 34765" Feb 18 05:49:12 volumio volumio[8738]: info: Loading plugin "i2s_dacs"... Feb 18 05:49:12 volumio volumio[8738]: info: Loading plugin "volumiodiscovery"... Feb 18 05:49:12 volumio volumio[8738]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 05:49:12 volumio volumio[8738]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:49:12 volumio volumio[8738]: *** WARNING *** For more information see Feb 18 05:49:12 volumio volumio[8738]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 05:49:12 volumio volumio[8738]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:49:12 volumio volumio[8738]: *** WARNING *** For more information see Feb 18 05:49:12 volumio node[8738]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 05:49:12 volumio node[8738]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:49:12 volumio node[8738]: *** WARNING *** For more information see Feb 18 05:49:12 volumio node[8738]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 05:49:12 volumio node[8738]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 05:49:12 volumio node[8738]: *** WARNING *** For more information see Feb 18 05:49:12 volumio volumio[8738]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 05:49:12 volumio volumio[8738]: info: Discovery: Started advertising with name: Volumio Feb 18 05:49:12 volumio go-librespot[8816]: time="2026-02-18T05:49:12+07:00" level=debug msg="obtained new client token: AAAunWmypo+zcxPGoWhdIds8sPTbM+s+nhvMdGAane7Uc1XmlWfjnu1J1M6wn2JhmFB1JrticsLBiLVnvCR7mLUfnKVm0AsAur8Zr+V2gJ9blPL79uh85dEiDAsKCDAm0XrTTcpHcqbUb8p4FAw2XJF4sSXJ8V8SN18DS0zQMK30rPgVsE1NPf2YCuK5hNSjt3j08Y1mmiloVygzXl3zNrBTdmPPM4shNYXBS2Z/xJ9hlQD4f6AHBtaDIw==" Feb 18 05:49:13 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 05:49:13 volumio volumio[8738]: info: Loading plugin "spop"... Feb 18 05:49:13 volumio go-librespot[8816]: time="2026-02-18T05:49:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:13 volumio go-librespot[8816]: time="2026-02-18T05:49:13+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:13 volumio go-librespot[8816]: time="2026-02-18T05:49:13+07:00" level=debug msg="completed challenge" Feb 18 05:49:13 volumio go-librespot[8816]: time="2026-02-18T05:49:13+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 18 05:49:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:14 volumio volumio[8738]: info: Loading plugin "ytcr"... Feb 18 05:49:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 18 05:49:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:16 volumio go-librespot[8829]: go-librespot daemon starting... Feb 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+07:00" level=debug msg="app state loaded" Feb 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+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 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+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 18 05:49:16 volumio go-librespot[8830]: time="2026-02-18T05:49:16+07:00" level=info msg="zeroconf server listening on port 44343" Feb 18 05:49:17 volumio go-librespot[8830]: time="2026-02-18T05:49:17+07:00" level=debug msg="obtained new client token: AADQlK7XCDH0OtIFUCWQjZ57EeSgXz0O31U/3PEEAyPQyAb9VnB2IC9Yo1AS+hLTr/1s0CmXS+5yo2c3moWtLbsdO6ZlFhZYWBMKCG2PgLfW6OyEexjAePHs1NbqG7t61WniZrG3Nyu+MA+YEQ0QB6lxqrV54kjwpov35ZdFL0xztUSNJX570yeN3KmfdjEqL1QYEDokWt0pfsWck0wSDuZPverQqe55mlUi3J6LusSs1r7iXNLA3RQ=" Feb 18 05:49:17 volumio go-librespot[8830]: time="2026-02-18T05:49:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:17 volumio go-librespot[8830]: time="2026-02-18T05:49:17+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:17 volumio go-librespot[8830]: time="2026-02-18T05:49:17+07:00" level=debug msg="completed challenge" Feb 18 05:49:17 volumio go-librespot[8830]: time="2026-02-18T05:49:17+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 18 05:49:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:17 volumio volumio[8738]: info: Loading plugin "ytmusic"... Feb 18 05:49:18 volumio volumio-remote-updater[25144]: [2026-02-18 05:49:18] [connect] Successful connection Feb 18 05:49:18 volumio volumio[8738]: info: Loading plugin "outputs"... Feb 18 05:49:18 volumio volumio[8738]: info: Loading plugin "albumart"... Feb 18 05:49:18 volumio volumio[8738]: info: Plugin example_plugin is not enabled Feb 18 05:49:18 volumio volumio[8738]: info: Loading plugin "inputs"... Feb 18 05:49:18 volumio volumio[8738]: info: Loading plugin "updater_comm"... Feb 18 05:49:18 volumio volumio[8738]: info: Plugin mpdemulation is not enabled Feb 18 05:49:18 volumio volumio[8738]: info: Loading plugin "rest_api"... Feb 18 05:49:19 volumio volumio[8738]: info: Loading plugin "websocket"... Feb 18 05:49:19 volumio volumio[8738]: info: Starting Socket.io Server version 1.7.4 Feb 18 05:49:19 volumio volumio[8738]: info: Loading plugin "RoonBridge"... Feb 18 05:49:19 volumio volumio[8738]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 05:49:19 volumio volumio[8738]: info: Loading i18n strings for locale en Feb 18 05:49:19 volumio volumio[8738]: Updating browse sources language Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:49:19 volumio volumio[8851]: Forking 3 albumart workers Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::initPlayerControls Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 05:49:19 volumio volumio[8738]: Express server listening on port 3000 Feb 18 05:49:19 volumio volumio[8738]: [Metrics] WebUI: 16s 134.37ms Feb 18 05:49:19 volumio volumio[8738]: info: CoreStateMachine::resetVolumioState Feb 18 05:49:19 volumio volumio[8738]: info: CoreStateMachine::getcurrentVolume Feb 18 05:49:19 volumio volumio[8738]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:49:20 volumio sudo[8893]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 05:49:20 volumio sudo[8893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:20 volumio sudo[8895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 05:49:20 volumio sudo[8895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:20 volumio sudo[8893]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:20 volumio volumio[8738]: info: Volumio Network Manager: Network status updated: 1 Feb 18 05:49:20 volumio sudo[8895]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:20 volumio volumio[8738]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::pushState Feb 18 05:49:20 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::volumioPushState Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::updateTrackBlock Feb 18 05:49:20 volumio volumio[8738]: info: CorePlayQueue::getTrackBlock Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:49:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 18 05:49:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:20 volumio volumio-remote-updater[25144]: [2026-02-18 05:49:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771368558 101 Feb 18 05:49:20 volumio volumio[8738]: 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 18 05:49:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:20 volumio go-librespot[8904]: go-librespot daemon starting... Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:20 volumio volumio[8738]: info: Reloading queue from file Feb 18 05:49:20 volumio go-librespot[8907]: time="2026-02-18T05:49:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:20 volumio go-librespot[8907]: time="2026-02-18T05:49:20+07:00" level=debug msg="app state loaded" Feb 18 05:49:20 volumio go-librespot[8907]: time="2026-02-18T05:49:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::setRepeat null single undefined Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::pushState Feb 18 05:49:20 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::volumioPushState Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::setRandom null Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::pushState Feb 18 05:49:20 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::volumioPushState Feb 18 05:49:20 volumio volumio[8738]: info: Setting Device type: Raspberry PI Feb 18 05:49:20 volumio volumio[8738]: info: Completed loading Core Plugins Feb 18 05:49:20 volumio volumio[8738]: info: Preparing to generate the ALSA configuration file Feb 18 05:49:20 volumio volumio[8738]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:49:20 volumio volumio[8738]: info: CoreStateMachine::pushState Feb 18 05:49:20 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:20 volumio volumio[8738]: info: CoreCommandRouter::volumioPushState Feb 18 05:49:21 volumio volumio[8738]: info: Asound.conf file unchanged, so no further update is needed Feb 18 05:49:21 volumio volumio[8738]: info: Output device has changed, restarting MPD Feb 18 05:49:21 volumio sudo[8920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 05:49:21 volumio sudo[8920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:21 volumio volumio[8738]: info: Output device has changed, restarting Shairport Sync Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:21 volumio sudo[8922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 05:49:21 volumio sudo[8922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:21 volumio volumio[8738]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 05:49:21 volumio volumio[8738]: info: ___________ START PLUGINS ___________ Feb 18 05:49:21 volumio sudo[8925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 05:49:21 volumio sudo[8925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:21 volumio volumio[8738]: info: ControllerMpd::onStart: Initializing MPD Feb 18 05:49:21 volumio volumio[8738]: info: Creating MPD Configuration file Feb 18 05:49:21 volumio sudo[8922]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:49:21 volumio volumio[8738]: info: [1771368561309] CoreMusicLibrary::Adding element Media Servers Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:49:21 volumio sudo[8920]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:21 volumio volumio[8738]: info: UPNP Browser: Client initialized successfully Feb 18 05:49:21 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 05:49:21 volumio sudo[8934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 05:49:21 volumio sudo[8936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 05:49:21 volumio sudo[8936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:21 volumio sudo[8934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:21 volumio sudo[8934]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:21 volumio go-librespot[8907]: time="2026-02-18T05:49:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:21 volumio go-librespot[8907]: time="2026-02-18T05:49:21+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 18 05:49:21 volumio go-librespot[8907]: time="2026-02-18T05:49:21+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 18 05:49:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 05:49:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 05:49:21 volumio go-librespot[8907]: time="2026-02-18T05:49:21+07:00" level=info msg="zeroconf server listening on port 44175" Feb 18 05:49:21 volumio systemd[1]: mpd.service: Consumed 6.983s CPU time. Feb 18 05:49:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 05:49:21 volumio volumio[8738]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 05:49:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 05:49:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:21 volumio volumio[8738]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:49:21 volumio volumio[8738]: info: [1771368561723] CoreMusicLibrary::Adding element Last_100 Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:49:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 05:49:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:49:21 volumio volumio[8738]: info: [1771368561760] CoreMusicLibrary::Adding element Webradio Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:49:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 05:49:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:49:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 05:49:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 05:49:21 volumio volumio[8738]: info: Initializing BBC Radios Feb 18 05:49:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 05:49:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 05:49:21 volumio go-librespot[8907]: time="2026-02-18T05:49:21+07:00" level=debug msg="obtained new client token: AAAXxge0GOsXD++mtt3bE3+RwJNGk5Gn3d7v5OQ9I7QH+FnLgU6HdoyziuWEcmApW3yNkCfsyxSMQNZdjZdmZY9MCpEmQO8LpA9IcxfmOqeznUDfwWqpyEQ6DXJOFwiU4mPFeCpyILVvI3sZK8qrERGNu+IpMJpFCH2jVkifLRkG+hC7ZxCpCS8f+vw4BsGxye0J/w5HAO7jg5zel9dp94OLHVkU+LkfUhFHtMzFE4oiU/lZ9hJnPBRp7g==" Feb 18 05:49:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 05:49:21 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:22 volumio volumio[8738]: info: Creating Spotify config file Feb 18 05:49:22 volumio go-librespot[8907]: time="2026-02-18T05:49:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:22 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:22 volumio go-librespot[8907]: time="2026-02-18T05:49:22+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:22 volumio go-librespot[8907]: time="2026-02-18T05:49:22+07:00" level=debug msg="completed challenge" Feb 18 05:49:22 volumio go-librespot[8907]: time="2026-02-18T05:49:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:49:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:22 volumio sudo[8959]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 05:49:22 volumio sudo[8959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 05:49:22 volumio sudo[8959]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:23 volumio volumio[8861]: Starting albumart workers Feb 18 05:49:23 volumio volumio[8738]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:49:23 volumio volumio[8738]: info: [1771368563110] CoreMusicLibrary::Adding element YouTube Music Feb 18 05:49:23 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:49:23 volumio volumio[8738]: Cannot find translation for source YouTube Music Feb 18 05:49:23 volumio volumio[8738]: info: Volumio Calling Home Feb 18 05:49:23 volumio sudo[8968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 05:49:23 volumio sudo[8968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:23 volumio sudo[8968]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:23 volumio volumio[8862]: Starting albumart workers Feb 18 05:49:23 volumio volumio[8863]: Starting albumart workers Feb 18 05:49:23 volumio volumio[8738]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 05:49:23 volumio volumio[8738]: info: Discovery: Found device Volumio Feb 18 05:49:23 volumio volumio[8738]: info: CoreCommandRouter::volumioGetState Feb 18 05:49:23 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:23 volumio volumio[8738]: info: MPD Permissions set Feb 18 05:49:23 volumio volumio[8738]: info: MPD Permissions set Feb 18 05:49:23 volumio volumio[8738]: info: Upmpdcli Daemon Started Feb 18 05:49:23 volumio volumio[8738]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 05:49:23 volumio volumio[8738]: info: Discovery: Found device Volumio Feb 18 05:49:23 volumio volumio[8738]: info: CoreCommandRouter::volumioGetState Feb 18 05:49:23 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:24 volumio volumio[8738]: info: Volumio called home Feb 18 05:49:24 volumio volumio[8738]: info: Spotify config file written Feb 18 05:49:24 volumio sudo[8974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 05:49:24 volumio sudo[8974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:24 volumio volumio[8738]: 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 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio go-librespot[8981]: go-librespot daemon starting... Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio sudo[8974]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:24 volumio go-librespot[8982]: time="2026-02-18T05:49:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:24 volumio go-librespot[8982]: time="2026-02-18T05:49:24+07:00" level=debug msg="app state loaded" Feb 18 05:49:24 volumio go-librespot[8982]: time="2026-02-18T05:49:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 05:49:24 volumio volumio[8738]: info: No need to fix Spotify hosts Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+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 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+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 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+07:00" level=info msg="zeroconf server listening on port 46831" Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+07:00" level=debug msg="obtained new client token: AAAFcqrw7P571DK0M0jxYROTX4HGNV3hpFm0mvVehejdV6hZg/KLYM2yW0pMi93Z5W+YDfv7Ic5YMiTidt7m0KCfFUiAThO6fRNLIoVaAcAzoX+SRlFbDJyifbQSRVySSm4HWyouGbkBdsRjeFa3mjEIsoGPPIWrSEu/c7e+JrgP0qX0k0p3GZwHoZWNinOZ3HA/u9cfEFDvdRlv/4h17dX+zkGGlABwBMiYnCk7bWGCOTwvYxgZ8aDPfQ==" Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49:25+07:00" level=debug msg="completed challenge" Feb 18 05:49:25 volumio go-librespot[8982]: time="2026-02-18T05:49: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 18 05:49:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:26 volumio volumio[8738]: info: Starting Shairport Sync Feb 18 05:49:26 volumio volumio[8738]: info: Starting Shairport Sync Feb 18 05:49:26 volumio volumio[8738]: info: Starting Shairport Sync Feb 18 05:49:26 volumio sudo[9014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:49:26 volumio sudo[9014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:26 volumio sudo[9016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:49:26 volumio sudo[9016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:26 volumio sudo[9018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 05:49:26 volumio sudo[9018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 05:49:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 05:49:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 05:49:26 volumio systemd[1]: shairport-sync.service: Consumed 2.287s CPU time. Feb 18 05:49:26 volumio volumio[8738]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 05:49:26 volumio volumio[8738]: SPOTIFY: BQDLS33Mqa5oFWI9Luw0fYPB-98a_O3ts9-iGtR5kNsN7B1pJ3LgRe2PR6fIpFTZ9kWPoESue02pTwLzWLh5u8kWtAd9sj6TeyX2oH1im-_dbd3Kwn9eVH8sREikbzvoD4g1BflSLAxG1UFJF4H5oqVW8juG-Xi2ScKKAfS3uqip_c8Jo1-Org7gp25gWq2_TqTNOqOhF2G1QAmh6MeWMJgzDyIos2lguXkCXa-I11A_lkrg4Z8t6iFj1LDjuP1GypdfCnee6rbI7QPvmfd2FhDf6bDKL5T--lXqpPVIW9qvHhsBXXc4RSWR Feb 18 05:49:26 volumio volumio[8738]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 05:49:26 volumio volumio[8738]: info: New Spotify access token = BQDLS33Mqa5oFWI9Luw0fYPB-98a_O3ts9-iGtR5kNsN7B1pJ3LgRe2PR6fIpFTZ9kWPoESue02pTwLzWLh5u8kWtAd9sj6TeyX2oH1im-_dbd3Kwn9eVH8sREikbzvoD4g1BflSLAxG1UFJF4H5oqVW8juG-Xi2ScKKAfS3uqip_c8Jo1-Org7gp25gWq2_TqTNOqOhF2G1QAmh6MeWMJgzDyIos2lguXkCXa-I11A_lkrg4Z8t6iFj1LDjuP1GypdfCnee6rbI7QPvmfd2FhDf6bDKL5T--lXqpPVIW9qvHhsBXXc4RSWR Feb 18 05:49:26 volumio volumio[8738]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 05:49:26 volumio volumio[8738]: info: CoreCommandRouter::volumioGetState Feb 18 05:49:26 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 05:49:26 volumio sudo[9014]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:26 volumio sudo[9016]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:26 volumio sudo[9018]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:26 volumio volumio[8738]: info: Shairport-Sync Started Feb 18 05:49:26 volumio volumio[8738]: Error adding Membership: Error: addMembership EINVAL Feb 18 05:49:26 volumio volumio[8738]: info: Shairport-Sync Started Feb 18 05:49:26 volumio volumio[8738]: info: Shairport-Sync Started Feb 18 05:49:26 volumio volumio[8738]: 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 18 05:49:26 volumio volumio[8738]: info: Spotify Successfully logged in Feb 18 05:49:26 volumio volumio[8738]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 05:49:26 volumio volumio[8738]: info: [1771368566878] CoreMusicLibrary::Adding element Spotify Feb 18 05:49:26 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 05:49:26 volumio volumio[8738]: Cannot find translation for source YouTube Music Feb 18 05:49:26 volumio volumio[8738]: Cannot find translation for source Spotify Feb 18 05:49:27 volumio volumio[8738]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 05:49:27 volumio volumio[8738]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 05:49:27 volumio volumio[8738]: info: VolumeController:: Volume=100 Mute =false Feb 18 05:49:27 volumio volumio[8738]: info: CoreCommandRouter::volumioGetState Feb 18 05:49:27 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:27 volumio volumio[8738]: info: CoreStateMachine::pushState Feb 18 05:49:27 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:27 volumio volumio[8738]: info: CoreCommandRouter::volumioPushState Feb 18 05:49:28 volumio volumio[8738]: info: go-librespot daemon successfully initialized Feb 18 05:49:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 18 05:49:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:29 volumio go-librespot[9053]: go-librespot daemon starting... Feb 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+07:00" level=debug msg="app state loaded" Feb 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:29 volumio mpd[8966]: 2026-02-18T05:49:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 05:49:29 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 05:49:29 volumio sudo[8925]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:29 volumio sudo[8936]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:29 volumio volumio[8738]: error: MPD error: The expression evaluated to a falsy value: Feb 18 05:49:29 volumio volumio[8738]: assert.ok(self.idling) Feb 18 05:49:29 volumio volumio[8738]: error: The expression evaluated to a falsy value: Feb 18 05:49:29 volumio volumio[8738]: assert.ok(self.idling) Feb 18 05:49:29 volumio volumio[8738]: info: MPD running with PID8966 Feb 18 05:49:29 volumio volumio[8738]: ,establishing connection Feb 18 05:49:29 volumio volumio[8738]: error: updateQueue error: null Feb 18 05:49:29 volumio volumio[8738]: info: Completed starting Core Plugins Feb 18 05:49:29 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:29 volumio volumio[8738]: info: ----- MyVolumio plugins startup ---- Feb 18 05:49:29 volumio volumio[8738]: info: ------------------------------------------- Feb 18 05:49:29 volumio volumio[8738]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+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 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+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 18 05:49:29 volumio volumio[8738]: error: updateQueue error: null Feb 18 05:49:29 volumio go-librespot[9054]: time="2026-02-18T05:49:29+07:00" level=info msg="zeroconf server listening on port 34619" Feb 18 05:49:30 volumio go-librespot[9054]: time="2026-02-18T05:49:30+07:00" level=debug msg="obtained new client token: AADqZBD4NmF9mWjK398XN9W41UfN2/9l25uPacaQZwGBV56mwmGwkqU1umfsloXgUw6gfI6Mjd6hELWglamGbKN3R+4tsIgsf550G8kmjit/iL3KTcJcYa9N5xAujynEvj/SXKqsjLe6MB9Rq+fnZtavkVFmc5chrdJJvwJgV5dm4dQ/nDXW4Zb0z3TQ8Cuh1nkBkhPCOM/9CxQK0axzqPQozt4hPIZMFihadV+LwUxeIULyQ+vkTR2apg==" Feb 18 05:49:30 volumio go-librespot[9054]: time="2026-02-18T05:49:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:30 volumio go-librespot[9054]: time="2026-02-18T05:49:30+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:30 volumio go-librespot[9054]: time="2026-02-18T05:49:30+07:00" level=debug msg="completed challenge" Feb 18 05:49:30 volumio go-librespot[9054]: time="2026-02-18T05:49:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:49:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:31 volumio volumio[8738]: info: Initializing connection to go-librespot Websocket Feb 18 05:49:32 volumio volumio[8738]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:49:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 18 05:49:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:33 volumio go-librespot[9069]: go-librespot daemon starting... Feb 18 05:49:33 volumio go-librespot[9070]: time="2026-02-18T05:49:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:33 volumio go-librespot[9070]: time="2026-02-18T05:49:33+07:00" level=debug msg="app state loaded" Feb 18 05:49:33 volumio go-librespot[9070]: time="2026-02-18T05:49:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+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 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+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 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+07:00" level=info msg="zeroconf server listening on port 35583" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+07:00" level=debug msg="obtained new client token: AAAdArTOKYCMxCfsgnZUAWdj1UsJQuyQxNyDHDj48j5QELuL7eeMptv8iShG3o+Qz1+D3vJ5lk5DcFgU1Ab/y1jxBsgKvSBl1dvTjv6z2QwSz4Zmn7i36ow/xJYdnMw0ZJR/ylxqw3X23BqWHCuZEUj6+yWzXpE/khuofFLTuKqDvE010SQUOuUdrL6NHosFAQeAAZ7hr8D9RK5Cc4huNVr2b8IDGYximz89s200MlLJUcSV8Lb909iqSA==" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+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 18 05:49:34 volumio volumio[8738]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+07:00" level=debug msg="completed challenge" Feb 18 05:49:34 volumio go-librespot[9070]: time="2026-02-18T05:49:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:49:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:35 volumio volumio[8738]: info: Initializing connection to go-librespot Websocket Feb 18 05:49:35 volumio volumio[8738]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 05:49:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 18 05:49:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:37 volumio go-librespot[9077]: go-librespot daemon starting... Feb 18 05:49:37 volumio go-librespot[9078]: time="2026-02-18T05:49:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:37 volumio go-librespot[9078]: time="2026-02-18T05:49:37+07:00" level=debug msg="app state loaded" Feb 18 05:49:37 volumio go-librespot[9078]: time="2026-02-18T05:49:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:38 volumio volumio[8738]: info: Initializing connection to go-librespot Websocket Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=debug msg="new websocket client" Feb 18 05:49:38 volumio volumio[8738]: info: Connection to go-librespot Websocket established Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+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 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+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 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=info msg="zeroconf server listening on port 37511" Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 05:49:38 volumio volumio[8738]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=debug msg="obtained new client token: AAAyBT0+3hXJfBh1woMsMZzoOQME7zZLFWr58zgW72g0MK7TToyl72SM42LtIVO1bLjbaFBsF4G//ow4cy//xgNW1cRHdD8fKy5ZyzfI27Ln5whRzBKT0P6haV2/tkV7HgwgMuCtNXoRYm1ceFzEvt2c+ilq1WeB8DWFrZtz5fctUT4VX/f89L2E7lZH9eXZDISsHwFJtm2rOdmHLG33Y15Yd94fgSo5OYf8Rr8aaUouY0GiHdyV4507ow==" Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=debug msg="completed challenge" Feb 18 05:49:38 volumio go-librespot[9078]: time="2026-02-18T05:49:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:49:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:40 volumio volumio[8738]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 05:49:40 volumio volumio[8738]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 05:49:40 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:40 volumio volumio[8738]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 05:49:40 volumio volumio[8738]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 05:49:40 volumio volumio[8738]: info: MyVolumio login type: Token Feb 18 05:49:40 volumio volumio[8738]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 05:49:40 volumio volumio[8738]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 05:49:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 18 05:49:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 05:49:42 volumio go-librespot[9099]: go-librespot daemon starting... Feb 18 05:49:42 volumio volumio[8738]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 05:49:42 volumio volumio[8738]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 05:49:42 volumio volumio[8738]: info: Streaming services startup Feb 18 05:49:42 volumio volumio[8738]: info: Starting Streaming Daemon Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=debug msg="app state loaded" Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 05:49:42 volumio sudo[9107]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 05:49:42 volumio sudo[9107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 05:49:42 volumio volumio[8738]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 05:49:42 volumio sudo[9107]: pam_unix(sudo:session): session closed for user root Feb 18 05:49:42 volumio volumio[8738]: info: Getting Spotify volume Feb 18 05:49:42 volumio volumio[8738]: info: Connection to go-librespot Websocket closed Feb 18 05:49:42 volumio volumio[8738]: error: Cannot start Volumio Streaming Daemon Feb 18 05:49:42 volumio volumio[8738]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 05:49:42 volumio volumio[8738]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 05:49:42 volumio volumio[8738]: 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 18 05:49:42 volumio volumio[8738]: info: CoreCommandRouter::volumioGetState Feb 18 05:49:42 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:42 volumio volumio[8738]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 05:49:42 volumio volumio[8738]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 05:49:42 volumio volumio[8738]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 05:49:42 volumio volumio[8738]: info: Aligning Spotify Volume to Volumio Volume Feb 18 05:49:42 volumio volumio[8738]: info: CoreCommandRouter::volumioGetState Feb 18 05:49:42 volumio volumio[8738]: info: CorePlayQueue::getTrack 0 Feb 18 05:49:42 volumio volumio[8738]: info: Setting Spotify Volume from Volumio: 100 Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=info msg="zeroconf server listening on port 39621" Feb 18 05:49:42 volumio go-librespot[9100]: time="2026-02-18T05:49:42+07:00" level=debug msg="obtained new client token: AABGq4PvU5iHkFHLiDZM4wPXtvjPgA4JAhmRj+j/D2jz2XURrE4TFbG8UjeWJTMYchwgt3qgMTbzA5gmfEcGT+aXkdxR5tUnrE11NrYWKNCjnLMurGe3WEGQCoYGso1pPvJp2F7BEn76Nyb4b+iIfXJ3uphYLER/tE3z4ZU9SIpR4Im8GEf88Mn98r6vmVnkWJ07XOv0/V3DhCokv2CBcHpS8QSII+07CoR7c2cqnl+pjbfn1kLkNp56Fw==" Feb 18 05:49:43 volumio go-librespot[9100]: time="2026-02-18T05:49:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 05:49:43 volumio go-librespot[9100]: time="2026-02-18T05:49:43+07:00" level=debug msg="completed keyexchange" Feb 18 05:49:43 volumio go-librespot[9100]: time="2026-02-18T05:49:43+07:00" level=debug msg="completed challenge" Feb 18 05:49:43 volumio go-librespot[9100]: time="2026-02-18T05:49:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 05:49:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 05:49:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 05:49:43 volumio volumio[8738]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 05:49:43 volumio volumio[8738]: Error: socket hang up Feb 18 05:49:43 volumio volumio[8738]: at connResetException (node:internal/errors:720:14) Feb 18 05:49:43 volumio volumio[8738]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 05:49:43 volumio volumio[8738]: at Socket.emit (node:events:526:35) Feb 18 05:49:43 volumio volumio[8738]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 05:49:43 volumio volumio[8738]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 05:49:43 volumio volumio[8738]: code: 'ECONNRESET', Feb 18 05:49:43 volumio volumio[8738]: response: undefined Feb 18 05:49:43 volumio volumio[8738]: } Feb 18 05:49:43 volumio volumio[8738]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 05:49:44 volumio sudo[9128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 05:48' Feb 18 05:49:44 volumio sudo[9128]: 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"