Feb 12 18:12:00 volumio volumio[19311]: info: Volumio Calling Home Feb 12 18:12:00 volumio sudo[19532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 18:12:00 volumio sudo[19532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:00 volumio sudo[19532]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:00 volumio volumio[19311]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 18:12:00 volumio volumio[19311]: info: Discovery: Found device Volumio Feb 12 18:12:00 volumio volumio[19311]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:00 volumio volumio[19311]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:00 volumio volumio[19311]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 18:12:00 volumio volumio[19311]: info: Discovery: Found device Volumio Feb 12 18:12:00 volumio volumio[19311]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:00 volumio volumio[19311]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:00 volumio volumio[19311]: info: MPD Permissions set Feb 12 18:12:00 volumio volumio[19311]: info: MPD Permissions set Feb 12 18:12:00 volumio volumio[19311]: info: Upmpdcli Daemon Started Feb 12 18:12:01 volumio volumio[19311]: info: Spotify config file written Feb 12 18:12:01 volumio sudo[19546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 18:12:01 volumio sudo[19546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:01 volumio volumio[19311]: 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 12 18:12:01 volumio volumio[19311]: info: Volumio called home Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:01 volumio go-librespot[19553]: go-librespot daemon starting... Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:01 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:01 volumio sudo[19546]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:01 volumio volumio[19311]: info: No need to fix Spotify hosts Feb 12 18:12:01 volumio go-librespot[19559]: time="2026-02-12T18:12:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:01 volumio go-librespot[19559]: time="2026-02-12T18:12:01+07:00" level=debug msg="app state loaded" Feb 12 18:12:01 volumio go-librespot[19559]: time="2026-02-12T18:12:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=info msg="zeroconf server listening on port 41231" Feb 12 18:12:02 volumio volumio[19311]: info: Starting Shairport Sync Feb 12 18:12:02 volumio volumio[19311]: info: Starting Shairport Sync Feb 12 18:12:02 volumio volumio[19311]: info: Starting Shairport Sync Feb 12 18:12:02 volumio sudo[19579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:12:02 volumio sudo[19579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="obtained new client token: AAB0Zcoa0ejj1yp/jsQUqGnRv41E2xwMbyTM5U7YBQ6DJNS7CRiP2CW4sTde71LjG2VmRnHT58n844NNDAFoOVMQmFU89GZYG+54Dv3Q4s4VhCkKQ+EEdh6sj/Awxm8J5vcKEjX6xNTEWyEqs2jh/N+EyKugOy4DXrAZ2i6ugixcqK6ZjV8HqPEkizD/P7Fbb7OloCTQ+igIqsSYBus/tZaCO1rthNbMkBwlj1P7RA+h/p7GhqvosafKng==" Feb 12 18:12:02 volumio sudo[19581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:12:02 volumio sudo[19581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:02 volumio sudo[19584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:12:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 18:12:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 18:12:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:12:02 volumio systemd[1]: shairport-sync.service: Consumed 2.204s CPU time. Feb 12 18:12:02 volumio sudo[19584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:12:02 volumio volumio[19311]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 18:12:02 volumio volumio[19311]: SPOTIFY: BQA_F1byh2_8KZCd0hpXuIm-SzM2haNSeldzdmcFXIDsS44QthJ1FpzzPV0rKqwfXtCaRYM5lNYFEsVDgzHe1132SzT-Q1vWQnVYKmVDLdX-k-DNWXzv4PYWcUajEWRr7jSx_a4kOdmCRLqt7MMjBK7Juz_iKkctoXrduzpwB33Hw00oMkaP0xZncU8LLOdbxr9WZzgawvdexrwjjSXBrd-841EJh41IkxDSvfYUlyjd0Y4-keVCOQUu10dFXOSPPEFzAGuvE2GuUOoT96cD2DRpijL3_auM81H1I-s9BSCX9g7giL7m152H Feb 12 18:12:02 volumio volumio[19311]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 18:12:02 volumio volumio[19311]: info: New Spotify access token = BQA_F1byh2_8KZCd0hpXuIm-SzM2haNSeldzdmcFXIDsS44QthJ1FpzzPV0rKqwfXtCaRYM5lNYFEsVDgzHe1132SzT-Q1vWQnVYKmVDLdX-k-DNWXzv4PYWcUajEWRr7jSx_a4kOdmCRLqt7MMjBK7Juz_iKkctoXrduzpwB33Hw00oMkaP0xZncU8LLOdbxr9WZzgawvdexrwjjSXBrd-841EJh41IkxDSvfYUlyjd0Y4-keVCOQUu10dFXOSPPEFzAGuvE2GuUOoT96cD2DRpijL3_auM81H1I-s9BSCX9g7giL7m152H Feb 12 18:12:02 volumio volumio[19311]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=debug msg="completed challenge" Feb 12 18:12:02 volumio sudo[19579]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:02 volumio volumio[19311]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:02 volumio volumio[19311]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:02 volumio go-librespot[19559]: time="2026-02-12T18:12:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 18:12:02 volumio volumio[19311]: info: Shairport-Sync Started Feb 12 18:12:02 volumio volumio[19311]: Error adding Membership: Error: addMembership EINVAL Feb 12 18:12:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 18:12:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:12:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:12:03 volumio sudo[19581]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:03 volumio sudo[19584]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:03 volumio volumio[19311]: info: Shairport-Sync Started Feb 12 18:12:03 volumio volumio[19311]: info: Shairport-Sync Started Feb 12 18:12:03 volumio volumio[19311]: 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 12 18:12:03 volumio volumio[19311]: info: Spotify Successfully logged in Feb 12 18:12:03 volumio volumio[19311]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:12:03 volumio volumio[19311]: info: [1770894723394] CoreMusicLibrary::Adding element Spotify Feb 12 18:12:03 volumio volumio[19311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:03 volumio volumio[19311]: Cannot find translation for source YouTube Music Feb 12 18:12:03 volumio volumio[19311]: Cannot find translation for source Spotify Feb 12 18:12:03 volumio volumio[19311]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 18:12:03 volumio volumio[19311]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:12:04 volumio volumio[19311]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:12:04 volumio volumio[19311]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:04 volumio volumio[19311]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:04 volumio volumio[19311]: info: CoreStateMachine::pushState Feb 12 18:12:04 volumio volumio[19311]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:04 volumio volumio[19311]: info: CoreCommandRouter::volumioPushState Feb 12 18:12:05 volumio volumio[19311]: info: go-librespot daemon successfully initialized Feb 12 18:12:05 volumio mpd[19530]: 2026-02-12T18:12:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 18:12:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 18:12:05 volumio sudo[19492]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:05 volumio sudo[19481]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:05 volumio volumio[19311]: error: MPD error: The expression evaluated to a falsy value: Feb 12 18:12:05 volumio volumio[19311]: assert.ok(self.idling) Feb 12 18:12:05 volumio volumio[19311]: error: The expression evaluated to a falsy value: Feb 12 18:12:05 volumio volumio[19311]: assert.ok(self.idling) Feb 12 18:12:05 volumio volumio[19311]: info: MPD running with PID19530 Feb 12 18:12:05 volumio volumio[19311]: ,establishing connection Feb 12 18:12:05 volumio volumio[19311]: error: updateQueue error: null Feb 12 18:12:05 volumio volumio[19311]: info: Completed starting Core Plugins Feb 12 18:12:05 volumio volumio[19311]: info: ------------------------------------------- Feb 12 18:12:05 volumio volumio[19311]: info: ----- MyVolumio plugins startup ---- Feb 12 18:12:05 volumio volumio[19311]: info: ------------------------------------------- Feb 12 18:12:05 volumio volumio[19311]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 18:12:05 volumio volumio[19311]: error: updateQueue error: null Feb 12 18:12:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 12 18:12:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:06 volumio go-librespot[19636]: go-librespot daemon starting... Feb 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+07:00" level=debug msg="app state loaded" Feb 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+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 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+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 12 18:12:06 volumio go-librespot[19637]: time="2026-02-12T18:12:06+07:00" level=info msg="zeroconf server listening on port 38003" Feb 12 18:12:07 volumio go-librespot[19637]: time="2026-02-12T18:12:07+07:00" level=debug msg="obtained new client token: AAA1Yo6inlDAkYWNslGd20VdKDT5oYPM9xAKyZpm8KnZKy67gsakZ9b/FBmL1BpTTpWPyDlT0lbcsYFVquLNnkifXy4O+AdW5uNWLvlGH+XXGUbkyukXSt6VIvwYUs6WQ/KBW0riMgPjamnqEOitAVzkTkSB9GzM/ZNqPsMXau/ISPCd2KW79ou/1h3IWsejc7YUQsG9Ml/JFQZTq23NWS54w4vv0k8ED0L/pQ/x46d0ZZZb0yPmibgmaA==" Feb 12 18:12:07 volumio go-librespot[19637]: time="2026-02-12T18:12:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:07 volumio go-librespot[19637]: time="2026-02-12T18:12:07+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:07 volumio go-librespot[19637]: time="2026-02-12T18:12:07+07:00" level=debug msg="completed challenge" Feb 12 18:12:07 volumio go-librespot[19637]: time="2026-02-12T18:12:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:08 volumio volumio[19311]: info: Initializing connection to go-librespot Websocket Feb 12 18:12:08 volumio volumio[19311]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 18:12:10 volumio volumio[19311]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 18:12:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 12 18:12:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:10 volumio go-librespot[19644]: go-librespot daemon starting... Feb 12 18:12:10 volumio go-librespot[19645]: time="2026-02-12T18:12:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:10 volumio go-librespot[19645]: time="2026-02-12T18:12:10+07:00" level=debug msg="app state loaded" Feb 12 18:12:10 volumio go-librespot[19645]: time="2026-02-12T18:12:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=info msg="zeroconf server listening on port 39197" Feb 12 18:12:11 volumio volumio[19311]: info: Initializing connection to go-librespot Websocket Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="new websocket client" Feb 12 18:12:11 volumio volumio[19311]: info: Connection to go-librespot Websocket established Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="obtained new client token: AADcu1NA0Q4E/yeC8N9wksN4uu1r2quvoPk0ViD7MBnUIlheSgEazQ1LYFuqnj9tX7et3FmDIZAXLJo57Vp6RgFy94s1b08hGBQXSt0xw3X6GoVLAw7NNPpwhgFAqdXI8R9Gs2bYSbqlXrp9q8VdWDhYCpN9vM07+0Yg5MlWY2//7yi9GUoNYE/dDI1ltKz1XvleUhz3WYG1mFa2P0UH7kvq4qjbL9E5kVIS6SzFOYZ4N2lcszQ91fw+Nw==" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=debug msg="completed challenge" Feb 12 18:12:11 volumio go-librespot[19645]: time="2026-02-12T18:12:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:11 volumio volumio[19311]: info: Connection to go-librespot Websocket closed Feb 12 18:12:14 volumio volumio[19311]: info: Getting Spotify volume Feb 12 18:12:14 volumio volumio[19311]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 18:12:14 volumio volumio[19311]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 18:12:14 volumio volumio[19311]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 18:12:14 volumio volumio[19311]: errno: -111, Feb 12 18:12:14 volumio volumio[19311]: code: 'ECONNREFUSED', Feb 12 18:12:14 volumio volumio[19311]: syscall: 'connect', Feb 12 18:12:14 volumio volumio[19311]: address: '127.0.0.1', Feb 12 18:12:14 volumio volumio[19311]: port: 9879, Feb 12 18:12:14 volumio volumio[19311]: response: undefined Feb 12 18:12:14 volumio volumio[19311]: } Feb 12 18:12:14 volumio volumio[19311]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 18:12:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 12 18:12:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:15 volumio go-librespot[19678]: go-librespot daemon starting... Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=debug msg="app state loaded" Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=info msg="zeroconf server listening on port 41617" Feb 12 18:12:15 volumio sudo[19689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 18:11' Feb 12 18:12:15 volumio sudo[19689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:15 volumio go-librespot[19679]: time="2026-02-12T18:12:15+07:00" level=debug msg="obtained new client token: AACGZgK7i2MO6+mzPVoL2PcZIVJv3W4z6v9YFraYcy6HF7fYzwBmeBZ62Fq6YWfOFnWigdjD6eN2mFbM77bxais+1qSMDPKDH8qqOYb6WoRnvwiuva1GlM5qBvaTFYtnnuf9JA4rwA7kgje1u4dSY9HouW/Je5CdnTeTq3ygWX2uYMAqG3YMUXdKCHMwostvXXDB9UIxJ0Di/WD9KYktSY8W8aDbA1N4qWtmxBg5sKzbAkO8OS08VFr7QA==" Feb 12 18:12:16 volumio go-librespot[19679]: time="2026-02-12T18:12:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:16 volumio sudo[19689]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:16 volumio go-librespot[19679]: time="2026-02-12T18:12:16+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:16 volumio go-librespot[19679]: time="2026-02-12T18:12:16+07:00" level=debug msg="completed challenge" Feb 12 18:12:16 volumio go-librespot[19679]: time="2026-02-12T18:12: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 12 18:12:16 volumio volumio-remote-updater[643]: [2026-02-12 18:12:16] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 18:12:16 volumio volumio-remote-updater[643]: [2026-02-12 18:12:16] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 18:12:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 18:12:16 volumio systemd[1]: volumio.service: Consumed 49.372s CPU time. Feb 12 18:12:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 18:12:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 18:12:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13549. Feb 12 18:12:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 18:12:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 18:12:16 volumio systemd[1]: volumio.service: Consumed 49.372s CPU time. Feb 12 18:12:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 18:12:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 18:12:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 12 18:12:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:19 volumio go-librespot[19716]: go-librespot daemon starting... Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=debug msg="app state loaded" Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:12:19 volumio go-librespot[19717]: time="2026-02-12T18:12:19+07:00" level=info msg="zeroconf server listening on port 46431" Feb 12 18:12:20 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:20 volumio volumio[19701]: info: ----- Volumio3 ---- Feb 12 18:12:20 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:20 volumio volumio[19701]: info: ----- System startup ---- Feb 12 18:12:20 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:20 volumio go-librespot[19717]: time="2026-02-12T18:12:20+07:00" level=debug msg="obtained new client token: AACMa8VD5Xf/eFTDJqYrtd9/0bgDPKQZmvH06Gl1FPSRMp6DdUZSPPKw+yqje43sX0wxU/St8md0t67aBkJV6HlszV0lihKzW3/SoRMu3YFA+1T0BSDm7IKuhJFJEz1i0a8LA4dEcuE0ieY9eiPW4hugMecpQ0dnk6IdZkKy5I8/laMV/7rAd1jfAZ7eEwpBECbuUoIws7C80sJjaOmLBWS/woCDzEFvz6LiVrj1JxS7cSZpa7kbvPs=" Feb 12 18:12:20 volumio go-librespot[19717]: time="2026-02-12T18:12:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:20 volumio go-librespot[19717]: time="2026-02-12T18:12:20+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:20 volumio go-librespot[19717]: time="2026-02-12T18:12:20+07:00" level=debug msg="completed challenge" Feb 12 18:12:20 volumio go-librespot[19717]: time="2026-02-12T18:12:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:21 volumio volumio-remote-updater[643]: [2026-02-12 18:12:21] [connect] Successful connection Feb 12 18:12:21 volumio volumio[19701]: info: MYVOLUMIO Environment detected Feb 12 18:12:21 volumio volumio[19701]: info: Plugin folders cleanup Feb 12 18:12:21 volumio volumio[19701]: info: Scanning into folder /volumio/app/plugins/ Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category audio_interface Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category miscellanea Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category music_service Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category plugins.json Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category system_controller Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category user_interface Feb 12 18:12:21 volumio volumio[19701]: info: Scanning into folder /data/plugins/ Feb 12 18:12:21 volumio volumio[19701]: info: Scanning category music_service Feb 12 18:12:21 volumio volumio[19701]: info: Plugin folders cleanup completed Feb 12 18:12:21 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:21 volumio volumio[19701]: info: ----- Core plugins startup ---- Feb 12 18:12:21 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:21 volumio volumio[19701]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 18:12:21 volumio volumio[19701]: info: Adding plugin upnp to MyMusic Plugins Feb 12 18:12:21 volumio volumio[19701]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 18:12:21 volumio volumio[19701]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 18:12:21 volumio volumio[19701]: info: Loading plugins from folder /data/plugins/ Feb 12 18:12:21 volumio volumio[19701]: info: Loading plugin "system"... Feb 12 18:12:21 volumio volumio[19701]: info: Loading plugin "appearance"... Feb 12 18:12:23 volumio volumio[19701]: info: Loading plugin "network"... Feb 12 18:12:23 volumio volumio[19701]: info: Refreshing Cached IP Addresses Feb 12 18:12:23 volumio sudo[19739]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 18:12:23 volumio sudo[19739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:23 volumio sudo[19739]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:23 volumio sudo[19741]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 18:12:23 volumio sudo[19741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:23 volumio sudo[19741]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:23 volumio volumio[19701]: info: Loading plugin "services"... Feb 12 18:12:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 12 18:12:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:23 volumio volumio[19701]: info: Loading plugin "alsa_controller"... Feb 12 18:12:23 volumio sudo[19749]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 18:12:23 volumio sudo[19749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:23 volumio go-librespot[19764]: go-librespot daemon starting... Feb 12 18:12:23 volumio go-librespot[19769]: time="2026-02-12T18:12:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:23 volumio go-librespot[19769]: time="2026-02-12T18:12:23+07:00" level=debug msg="app state loaded" Feb 12 18:12:23 volumio go-librespot[19769]: time="2026-02-12T18:12:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:23 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 18:12:23 volumio volumio[19701]: info: Loading plugin "wizard"... Feb 12 18:12:23 volumio volumio[19701]: info: Loading plugin "networkfs"... Feb 12 18:12:24 volumio volumio[19701]: info: Starting Udev Watcher for removable devices Feb 12 18:12:24 volumio volumio[19701]: info: Ignoring mount for partition: boot Feb 12 18:12:24 volumio volumio[19701]: info: Ignoring mount for partition: volumio Feb 12 18:12:24 volumio volumio[19701]: info: Ignoring mount for partition: volumio_data Feb 12 18:12:24 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 18:12:24 volumio volumio[19701]: info: Loading plugin "volumio_command_line_client"... Feb 12 18:12:24 volumio volumio[19701]: info: Loading plugin "upnp"... Feb 12 18:12:24 volumio volumio[19701]: info: [1770894744131] Starting Upmpd Daemon Feb 12 18:12:24 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 18:12:24 volumio volumio[19701]: info: Loading plugin "my_music"... Feb 12 18:12:24 volumio volumio[19701]: info: Loading plugin "mpd"... Feb 12 18:12:24 volumio go-librespot[19769]: time="2026-02-12T18:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:24 volumio go-librespot[19769]: time="2026-02-12T18:12:24+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 12 18:12:24 volumio go-librespot[19769]: time="2026-02-12T18:12:24+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 12 18:12:24 volumio go-librespot[19769]: time="2026-02-12T18:12:24+07:00" level=info msg="zeroconf server listening on port 41385" Feb 12 18:12:24 volumio volumio[19701]: info: Loading plugin "upnp_browser"... Feb 12 18:12:24 volumio go-librespot[19769]: time="2026-02-12T18:12:24+07:00" level=debug msg="obtained new client token: AABG+IIA9wjCsUCYTq6Z4PEhwKZonGoj7+gN6vDG0EkjJI0fANdP/vykhZjXFMrjPYgMZYtnS4DFA1qfOZsu6amw2DosJSSHZNZLsUTzkreIctBPCiJ1i3UMTY8+fZCaIPWL6MPwEmALfjcdOCsScHjgquBGJE+6Y4JmpWx0H/Edw8hGGAq5j7uDlwSKOYMVjnVHw/zcZ21mCytV1uThPhHJe5o9qtGbVUYIfQiMeyE9iDIZz03/+e86Ag==" Feb 12 18:12:25 volumio go-librespot[19769]: time="2026-02-12T18:12:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:25 volumio go-librespot[19769]: time="2026-02-12T18:12:25+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:25 volumio go-librespot[19769]: time="2026-02-12T18:12:25+07:00" level=debug msg="completed challenge" Feb 12 18:12:25 volumio go-librespot[19769]: time="2026-02-12T18:12: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 12 18:12:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:26 volumio sudo[19749]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:27 volumio volumio[19701]: info: Starting UPNP Browser Feb 12 18:12:27 volumio volumio[19701]: info: Loading plugin "alarm-clock"... Feb 12 18:12:28 volumio volumio[19701]: info: Loading plugin "airplay_emulation"... Feb 12 18:12:28 volumio volumio[19701]: info: Starting Shairport Sync Feb 12 18:12:28 volumio volumio[19701]: info: Loading plugin "last_100"... Feb 12 18:12:28 volumio volumio[19701]: info: Loading plugin "webradio"... Feb 12 18:12:28 volumio volumio[19701]: info: Loading plugin "i2s_dacs"... Feb 12 18:12:28 volumio volumio[19701]: info: Loading plugin "volumiodiscovery"... Feb 12 18:12:28 volumio volumio[19701]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 18:12:28 volumio volumio[19701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:12:28 volumio node[19701]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 18:12:28 volumio volumio[19701]: *** WARNING *** For more information see Feb 12 18:12:28 volumio volumio[19701]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 18:12:28 volumio volumio[19701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:12:28 volumio volumio[19701]: *** WARNING *** For more information see Feb 12 18:12:28 volumio node[19701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:12:28 volumio node[19701]: *** WARNING *** For more information see Feb 12 18:12:28 volumio node[19701]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 18:12:28 volumio node[19701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:12:28 volumio node[19701]: *** WARNING *** For more information see Feb 12 18:12:28 volumio volumio[19701]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 18:12:28 volumio volumio[19701]: info: Discovery: Started advertising with name: Volumio Feb 12 18:12:28 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 18:12:28 volumio volumio[19701]: info: Loading plugin "spop"... Feb 12 18:12:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 12 18:12:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:28 volumio go-librespot[19782]: go-librespot daemon starting... Feb 12 18:12:28 volumio go-librespot[19783]: time="2026-02-12T18:12:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:28 volumio go-librespot[19783]: time="2026-02-12T18:12:28+07:00" level=debug msg="app state loaded" Feb 12 18:12:28 volumio go-librespot[19783]: time="2026-02-12T18:12:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=info msg="zeroconf server listening on port 39111" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="obtained new client token: AACYJKF0EGDsP9+QwZ0/5UM5j/SQ/2uBn3U1wWI4vI+HUesu1IZeowrUfTiDPVX8D12zbrDX64GXmTp7XZVzy72pqicHeiGpJMRceZJ3CrsJmX8RYliKMUja5CU3+0wKCaQdUimmz3W2u1/yDM5q8Pu+sjUfp8YhYfuGMhYnKe1kQ0llMKnQknSz8MZ5D4N0apmQZYrOPPHolxXRwkQ3WaiMecYmayyOm4mQGm6muNCsJXeVSi+JKjX+mQ==" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12:29+07:00" level=debug msg="completed challenge" Feb 12 18:12:29 volumio go-librespot[19783]: time="2026-02-12T18:12: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 12 18:12:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:30 volumio volumio[19701]: info: Loading plugin "ytcr"... Feb 12 18:12:32 volumio volumio[19701]: info: Loading plugin "ytmusic"... Feb 12 18:12:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 12 18:12:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:33 volumio go-librespot[19791]: go-librespot daemon starting... Feb 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12:33+07:00" level=debug msg="app state loaded" Feb 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12:33+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 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12:33+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 12 18:12:33 volumio go-librespot[19792]: time="2026-02-12T18:12:33+07:00" level=info msg="zeroconf server listening on port 32877" Feb 12 18:12:33 volumio volumio-remote-updater[643]: [2026-02-12 18:12:33] [connect] Successful connection Feb 12 18:12:34 volumio go-librespot[19792]: time="2026-02-12T18:12:34+07:00" level=debug msg="obtained new client token: AADHECfWqiuT+herSsLC0rbk67m1HcOzIIbCof0C5GUPd52bAZQ6oZSZ1r7+z6gr035cRny4sgVzKnytXRsmGg0QwVZAT8BxIxf2eWaTcoz7KKh0M5aOgO8g4vkKvP3fRbv6NeL1gzEabvmPXpDm63nge007aYBTvwfpxuH4kjcISmo/YM66o+iIJu0qeB1UK5+Vf7woOg4w3lAPx1boMolPwC4Hv1wRG0KG9SyzhHxSHoTTr07d" Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "outputs"... Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "albumart"... Feb 12 18:12:34 volumio volumio[19701]: info: Plugin example_plugin is not enabled Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "inputs"... Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "updater_comm"... Feb 12 18:12:34 volumio go-librespot[19792]: time="2026-02-12T18:12:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:34 volumio go-librespot[19792]: time="2026-02-12T18:12:34+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:34 volumio go-librespot[19792]: time="2026-02-12T18:12:34+07:00" level=debug msg="completed challenge" Feb 12 18:12:34 volumio volumio[19701]: info: Plugin mpdemulation is not enabled Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "rest_api"... Feb 12 18:12:34 volumio go-librespot[19792]: time="2026-02-12T18:12: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 12 18:12:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "websocket"... Feb 12 18:12:34 volumio volumio[19701]: info: Starting Socket.io Server version 1.7.4 Feb 12 18:12:34 volumio volumio[19701]: info: Loading plugin "RoonBridge"... Feb 12 18:12:34 volumio volumio[19701]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 18:12:35 volumio volumio[19701]: info: Loading i18n strings for locale en Feb 12 18:12:35 volumio volumio[19701]: Updating browse sources language Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:35 volumio volumio[19813]: Forking 3 albumart workers Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::initPlayerControls Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 18:12:35 volumio volumio[19701]: Express server listening on port 3000 Feb 12 18:12:35 volumio volumio[19701]: [Metrics] WebUI: 16s 223.85ms Feb 12 18:12:35 volumio volumio[19701]: info: CoreStateMachine::resetVolumioState Feb 12 18:12:35 volumio volumio[19701]: info: CoreStateMachine::getcurrentVolume Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:12:35 volumio sudo[19858]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 18:12:35 volumio sudo[19858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:35 volumio sudo[19858]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:35 volumio sudo[19860]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 18:12:35 volumio sudo[19860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:35 volumio sudo[19860]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:35 volumio volumio[19701]: info: Volumio Network Manager: Network status updated: 1 Feb 12 18:12:35 volumio volumio-remote-updater[643]: [2026-02-12 18:12:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770894753 101 Feb 12 18:12:35 volumio volumio[19701]: 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 12 18:12:35 volumio volumio[19701]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:12:35 volumio volumio[19701]: info: CoreStateMachine::pushState Feb 12 18:12:35 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::volumioPushState Feb 12 18:12:35 volumio volumio[19701]: info: CoreStateMachine::updateTrackBlock Feb 12 18:12:35 volumio volumio[19701]: info: CorePlayQueue::getTrackBlock Feb 12 18:12:35 volumio volumio[19701]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:36 volumio volumio[19701]: info: Reloading queue from file Feb 12 18:12:36 volumio volumio[19701]: info: CoreStateMachine::setRepeat null single undefined Feb 12 18:12:36 volumio volumio[19701]: info: CoreStateMachine::pushState Feb 12 18:12:36 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::volumioPushState Feb 12 18:12:36 volumio volumio[19701]: info: CoreStateMachine::setRandom null Feb 12 18:12:36 volumio volumio[19701]: info: CoreStateMachine::pushState Feb 12 18:12:36 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::volumioPushState Feb 12 18:12:36 volumio volumio[19701]: info: Setting Device type: Raspberry PI Feb 12 18:12:36 volumio volumio[19701]: info: Completed loading Core Plugins Feb 12 18:12:36 volumio volumio[19701]: info: Preparing to generate the ALSA configuration file Feb 12 18:12:36 volumio volumio[19701]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:12:36 volumio volumio[19701]: info: CoreStateMachine::pushState Feb 12 18:12:36 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::volumioPushState Feb 12 18:12:36 volumio volumio[19701]: info: Asound.conf file unchanged, so no further update is needed Feb 12 18:12:36 volumio volumio[19701]: info: Output device has changed, restarting MPD Feb 12 18:12:36 volumio volumio[19701]: info: Output device has changed, restarting Shairport Sync Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:36 volumio sudo[19873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 18:12:36 volumio sudo[19873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:36 volumio volumio[19701]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 18:12:36 volumio volumio[19701]: info: ___________ START PLUGINS ___________ Feb 12 18:12:36 volumio sudo[19875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 18:12:36 volumio sudo[19875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:36 volumio sudo[19877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 18:12:36 volumio sudo[19877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:36 volumio volumio[19701]: info: ControllerMpd::onStart: Initializing MPD Feb 12 18:12:36 volumio volumio[19701]: info: Creating MPD Configuration file Feb 12 18:12:36 volumio sudo[19875]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:12:36 volumio volumio[19701]: info: [1770894756628] CoreMusicLibrary::Adding element Media Servers Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 18:12:36 volumio sudo[19886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 18:12:36 volumio sudo[19886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:36 volumio sudo[19873]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:36 volumio sudo[19886]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:36 volumio volumio[19701]: info: UPNP Browser: Client initialized successfully Feb 12 18:12:36 volumio sudo[19888]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 18:12:36 volumio sudo[19888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 18:12:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 18:12:36 volumio systemd[1]: mpd.service: Consumed 7.155s CPU time. Feb 12 18:12:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 18:12:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 18:12:36 volumio volumio[19701]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 18:12:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 18:12:36 volumio volumio[19701]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:12:36 volumio volumio[19701]: info: [1770894756979] CoreMusicLibrary::Adding element Last_100 Feb 12 18:12:36 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 18:12:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 18:12:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 18:12:37 volumio volumio[19701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:12:37 volumio volumio[19701]: info: [1770894757022] CoreMusicLibrary::Adding element Webradio Feb 12 18:12:37 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 18:12:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 18:12:37 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 18:12:37 volumio volumio[19701]: info: Initializing BBC Radios Feb 12 18:12:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 18:12:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 18:12:37 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 18:12:37 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:37 volumio volumio[19701]: info: Creating Spotify config file Feb 12 18:12:37 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 12 18:12:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:37 volumio sudo[19912]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 18:12:37 volumio sudo[19912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 18:12:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:37 volumio sudo[19912]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:37 volumio go-librespot[19916]: go-librespot daemon starting... Feb 12 18:12:37 volumio go-librespot[19918]: time="2026-02-12T18:12:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:38 volumio volumio[19825]: Starting albumart workers Feb 12 18:12:38 volumio volumio[19824]: Starting albumart workers Feb 12 18:12:38 volumio volumio[19701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:12:38 volumio volumio[19701]: info: [1770894758585] CoreMusicLibrary::Adding element YouTube Music Feb 12 18:12:38 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:38 volumio volumio[19701]: Cannot find translation for source YouTube Music Feb 12 18:12:38 volumio volumio[19701]: info: Volumio Calling Home Feb 12 18:12:38 volumio go-librespot[19918]: time="2026-02-12T18:12:38+07:00" level=info msg="zeroconf server listening on port 44269" Feb 12 18:12:38 volumio sudo[19928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 18:12:38 volumio sudo[19928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:38 volumio sudo[19928]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:39 volumio volumio[19823]: Starting albumart workers Feb 12 18:12:39 volumio volumio[19701]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 18:12:39 volumio volumio[19701]: info: Discovery: Found device Volumio Feb 12 18:12:39 volumio volumio[19701]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:39 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:39 volumio volumio[19701]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 18:12:39 volumio volumio[19701]: info: Discovery: Found device Volumio Feb 12 18:12:39 volumio volumio[19701]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:39 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:39 volumio volumio[19701]: info: MPD Permissions set Feb 12 18:12:39 volumio volumio[19701]: info: MPD Permissions set Feb 12 18:12:39 volumio volumio[19701]: info: Upmpdcli Daemon Started Feb 12 18:12:39 volumio volumio[19701]: info: Volumio called home Feb 12 18:12:39 volumio volumio[19701]: info: Spotify config file written Feb 12 18:12:39 volumio sudo[19935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 18:12:39 volumio sudo[19935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:39 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 18:12:39 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 18:12:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:39 volumio volumio[19701]: 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 12 18:12:39 volumio go-librespot[19937]: go-librespot daemon starting... Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio sudo[19935]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+07:00" level=debug msg="app state loaded" Feb 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:12:40 volumio volumio[19701]: info: No need to fix Spotify hosts Feb 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+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 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+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 12 18:12:40 volumio go-librespot[19938]: time="2026-02-12T18:12:40+07:00" level=info msg="zeroconf server listening on port 34561" Feb 12 18:12:41 volumio go-librespot[19938]: time="2026-02-12T18:12:41+07:00" level=debug msg="obtained new client token: AAC47Bf/SgkyriDx6ReaodW0je4xe2mVUOWTrvdodkA9qirurxb9rNh2SrlTlcCuKG1PiGpoN89AGsw18TdodATi/CctwJdIZ+TX+TfwV7xt44PZJ7qbJtsz+X193Hjq3Gqb4z7Np00MZQdOCuissK6mxmXdiSAnI7AkKylTkMzxGgip/brFiygbt6VwduIW0BUk2Npaxn5xlht4I32L8sugykTk8a5dID2vDFyoBqrXwy2auSr1/+6anA==" Feb 12 18:12:41 volumio go-librespot[19938]: time="2026-02-12T18:12:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:41 volumio go-librespot[19938]: time="2026-02-12T18:12:41+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:41 volumio go-librespot[19938]: time="2026-02-12T18:12:41+07:00" level=debug msg="completed challenge" Feb 12 18:12:41 volumio volumio[19701]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 18:12:41 volumio volumio[19701]: SPOTIFY: BQArirZ3F0r9u_vwR7Iiq6NsNQYoXxZiuYp8cUO7orSBe1dBkvTqLrIqDeRTbGU87gFIIo8xdMizw76hJ1pm9wbypr5iPBJpzg-EWjI8Y47ABn2XaD_UKsXzWBefMu08LsaoYhspuRpCw6o1wy24lIei4bIrjhzrTtrN2xvmDEZlB1gccX_tZ2wZiANS0PaTWikQNdtjoUv2IgbH2NfKmvIUzQlNCa05O5AKIYP4_Ah1fRHeYwBdZGTXnpZnckiHySaSnyiSwgcYwsqE9gl5we2GhL9jrgsluSzciD2dcDsKkVRiZLm6YjuR Feb 12 18:12:41 volumio volumio[19701]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 18:12:41 volumio volumio[19701]: info: New Spotify access token = BQArirZ3F0r9u_vwR7Iiq6NsNQYoXxZiuYp8cUO7orSBe1dBkvTqLrIqDeRTbGU87gFIIo8xdMizw76hJ1pm9wbypr5iPBJpzg-EWjI8Y47ABn2XaD_UKsXzWBefMu08LsaoYhspuRpCw6o1wy24lIei4bIrjhzrTtrN2xvmDEZlB1gccX_tZ2wZiANS0PaTWikQNdtjoUv2IgbH2NfKmvIUzQlNCa05O5AKIYP4_Ah1fRHeYwBdZGTXnpZnckiHySaSnyiSwgcYwsqE9gl5we2GhL9jrgsluSzciD2dcDsKkVRiZLm6YjuR Feb 12 18:12:41 volumio volumio[19701]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 18:12:41 volumio go-librespot[19938]: time="2026-02-12T18:12:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:41 volumio volumio[19701]: info: Starting Shairport Sync Feb 12 18:12:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:41 volumio volumio[19701]: info: Starting Shairport Sync Feb 12 18:12:41 volumio volumio[19701]: info: Starting Shairport Sync Feb 12 18:12:41 volumio sudo[19974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:12:41 volumio sudo[19974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:41 volumio sudo[19978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:12:41 volumio sudo[19976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:12:41 volumio sudo[19978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:41 volumio sudo[19976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 18:12:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 18:12:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:12:41 volumio systemd[1]: shairport-sync.service: Consumed 2.196s CPU time. Feb 12 18:12:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:12:41 volumio sudo[19976]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:41 volumio sudo[19978]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:41 volumio sudo[19974]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:41 volumio volumio[19701]: info: Shairport-Sync Started Feb 12 18:12:41 volumio volumio[19701]: Error adding Membership: Error: addMembership EINVAL Feb 12 18:12:41 volumio volumio[19701]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:41 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:41 volumio volumio[19701]: info: Shairport-Sync Started Feb 12 18:12:41 volumio volumio[19701]: info: Shairport-Sync Started Feb 12 18:12:42 volumio volumio[19701]: 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 12 18:12:42 volumio volumio[19701]: info: Spotify Successfully logged in Feb 12 18:12:42 volumio volumio[19701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:12:42 volumio volumio[19701]: info: [1770894762209] CoreMusicLibrary::Adding element Spotify Feb 12 18:12:42 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:12:42 volumio volumio[19701]: Cannot find translation for source YouTube Music Feb 12 18:12:42 volumio volumio[19701]: Cannot find translation for source Spotify Feb 12 18:12:42 volumio volumio[19701]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 18:12:42 volumio volumio[19701]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:12:43 volumio volumio[19701]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:12:43 volumio volumio[19701]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:43 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:43 volumio volumio[19701]: info: CoreStateMachine::pushState Feb 12 18:12:43 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:43 volumio volumio[19701]: info: CoreCommandRouter::volumioPushState Feb 12 18:12:44 volumio volumio[19701]: info: go-librespot daemon successfully initialized Feb 12 18:12:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 18:12:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:44 volumio mpd[19924]: 2026-02-12T18:12:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 18:12:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:44 volumio go-librespot[20016]: go-librespot daemon starting... Feb 12 18:12:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 18:12:44 volumio sudo[19877]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:44 volumio sudo[19888]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:44 volumio go-librespot[20019]: time="2026-02-12T18:12:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:44 volumio go-librespot[20019]: time="2026-02-12T18:12:44+07:00" level=debug msg="app state loaded" Feb 12 18:12:44 volumio go-librespot[20019]: time="2026-02-12T18:12:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:44 volumio volumio[19701]: error: MPD error: The expression evaluated to a falsy value: Feb 12 18:12:44 volumio volumio[19701]: assert.ok(self.idling) Feb 12 18:12:44 volumio volumio[19701]: error: The expression evaluated to a falsy value: Feb 12 18:12:44 volumio volumio[19701]: assert.ok(self.idling) Feb 12 18:12:44 volumio volumio[19701]: info: MPD running with PID19924 Feb 12 18:12:44 volumio volumio[19701]: ,establishing connection Feb 12 18:12:44 volumio volumio[19701]: error: updateQueue error: null Feb 12 18:12:45 volumio volumio[19701]: info: Completed starting Core Plugins Feb 12 18:12:45 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:45 volumio volumio[19701]: info: ----- MyVolumio plugins startup ---- Feb 12 18:12:45 volumio volumio[19701]: info: ------------------------------------------- Feb 12 18:12:45 volumio volumio[19701]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 18:12:45 volumio volumio[19701]: error: updateQueue error: null Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=info msg="zeroconf server listening on port 45557" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="obtained new client token: AAD3qQXhzsmwzRQd1xhUfkymTzpc9RiLUnWwMJALMFamvwrKBy+Q5hMiIiH4cHydNKxaWK9Ulpo3Id8j9dgarBum4K05BmvfFOpaEIfp6kyc1+nVil6/Z5LqDJ/mgnVM8aD7aXxDbr5jCOqxcyLBB3qZnDs6cgqTK5mf9MxHQEpAHbSgWL1u14ZSlkJ15n6Svx6Uu8sX3QpoUpPMAESOY8d/Af0RrD4+yWZoHT+2gl+uyuOUIeFBu/QiPQ==" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=debug msg="completed challenge" Feb 12 18:12:45 volumio go-librespot[20019]: time="2026-02-12T18:12:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:47 volumio volumio[19701]: info: Initializing connection to go-librespot Websocket Feb 12 18:12:47 volumio volumio[19701]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 18:12:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 18:12:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:48 volumio go-librespot[20028]: go-librespot daemon starting... Feb 12 18:12:48 volumio go-librespot[20029]: time="2026-02-12T18:12:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:48 volumio go-librespot[20029]: time="2026-02-12T18:12:48+07:00" level=debug msg="app state loaded" Feb 12 18:12:48 volumio go-librespot[20029]: time="2026-02-12T18:12:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=info msg="zeroconf server listening on port 46631" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="obtained new client token: AADdzKaFTDyh/an5cOrqFyjA9pj7uAypFRY/jxTBkIl9Aa8ZQCq74bBK/FNG/E/r6qAONaOQldolnW0YTC1oCZ1jJRcrUBOz9ZdOPW6FOq0t2INy8oZyHKFSqB6eDmqeMRZLxq88D0mEBPtE4r30wbWyIDBaEnIYTKB7JOhZo/n32u05Iz+Dav7qthmPHEiJGlA+JmUZuHcfw0tul7dSEiFWhk4XuvLtqV8Rg25sALXykj7VW7XFd7eAFA==" Feb 12 18:12:49 volumio volumio[19701]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:49 volumio go-librespot[20029]: time="2026-02-12T18:12:49+07:00" level=debug msg="completed challenge" Feb 12 18:12:50 volumio go-librespot[20029]: time="2026-02-12T18:12:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:50 volumio volumio[19701]: info: Initializing connection to go-librespot Websocket Feb 12 18:12:50 volumio volumio[19701]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 18:12:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 18:12:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:53 volumio go-librespot[20036]: go-librespot daemon starting... Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=debug msg="app state loaded" Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:53 volumio volumio[19701]: info: Initializing connection to go-librespot Websocket Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=debug msg="new websocket client" Feb 12 18:12:53 volumio volumio[19701]: info: Connection to go-librespot Websocket established Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:12:53 volumio go-librespot[20037]: time="2026-02-12T18:12:53+07:00" level=info msg="zeroconf server listening on port 39811" Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 18:12:53 volumio volumio[19701]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 18:12:54 volumio go-librespot[20037]: time="2026-02-12T18:12:54+07:00" level=debug msg="obtained new client token: AAAsBBJwYb7hTDI48Esgw55oKWUTiGKUGkXkfAH3cmvI9LikyW2+xpQsjSrDOAN0f8M4lYzU4g0R6fN0Mnni2rqWYjUl1GtN/759oKKfIjWagoLK5P2/wnHXTl5L4OqkwpS99IXd26/W7366ZSl+OPTq5K60Scud/P4bFtkowDupUpKiC0FsiY5Ls+gS4uQDGbDz0nwGQsC/DewLcGNpeTzyHCi1hTFEf8xwwOwx/4hZfT+q1fdi22N/yg==" Feb 12 18:12:54 volumio go-librespot[20037]: time="2026-02-12T18:12:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:54 volumio go-librespot[20037]: time="2026-02-12T18:12:54+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:54 volumio go-librespot[20037]: time="2026-02-12T18:12:54+07:00" level=debug msg="completed challenge" Feb 12 18:12:54 volumio go-librespot[20037]: time="2026-02-12T18:12:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:55 volumio volumio[19701]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 18:12:55 volumio volumio[19701]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 18:12:55 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:55 volumio volumio[19701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:12:55 volumio volumio[19701]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 18:12:55 volumio volumio[19701]: info: MyVolumio login type: Token Feb 12 18:12:55 volumio volumio[19701]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 18:12:55 volumio volumio[19701]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 18:12:57 volumio volumio[19701]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 18:12:57 volumio volumio[19701]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 18:12:57 volumio volumio[19701]: info: Streaming services startup Feb 12 18:12:57 volumio volumio[19701]: info: Starting Streaming Daemon Feb 12 18:12:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 18:12:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:57 volumio volumio[19701]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 18:12:57 volumio sudo[20059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 18:12:57 volumio sudo[20059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:12:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:12:57 volumio go-librespot[20064]: go-librespot daemon starting... Feb 12 18:12:57 volumio sudo[20059]: pam_unix(sudo:session): session closed for user root Feb 12 18:12:57 volumio go-librespot[20066]: time="2026-02-12T18:12:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:12:57 volumio go-librespot[20066]: time="2026-02-12T18:12:57+07:00" level=debug msg="app state loaded" Feb 12 18:12:57 volumio go-librespot[20066]: time="2026-02-12T18:12:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:12:57 volumio volumio[19701]: info: Getting Spotify volume Feb 12 18:12:57 volumio volumio[19701]: info: Connection to go-librespot Websocket closed Feb 12 18:12:57 volumio volumio[19701]: error: Cannot start Volumio Streaming Daemon Feb 12 18:12:57 volumio volumio[19701]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 18:12:57 volumio volumio[19701]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 18:12:57 volumio volumio[19701]: 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 12 18:12:58 volumio volumio[19701]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:58 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:58 volumio volumio[19701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 18:12:58 volumio volumio[19701]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 18:12:58 volumio volumio[19701]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 18:12:58 volumio volumio[19701]: info: Aligning Spotify Volume to Volumio Volume Feb 12 18:12:58 volumio volumio[19701]: info: CoreCommandRouter::volumioGetState Feb 12 18:12:58 volumio volumio[19701]: info: CorePlayQueue::getTrack 0 Feb 12 18:12:58 volumio volumio[19701]: info: Setting Spotify Volume from Volumio: 100 Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+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 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+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 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=info msg="zeroconf server listening on port 33067" Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=debug msg="obtained new client token: AADlCh7loxrz0wR25yi+3FOWcCcKm4yV9ygo2R6d1p3t7+zb88m89MR1PMDK3pvJ2pWw8RyHsYiaPnYVzjvJXEq150c5i4+LQQHyxkrMfGSGf9mEeQvmVCBKymjLImbFL0g0v5pBKQTn7+xMArdX6IIrwQ0YanhehTo+5bLqnSmz9aWGLVt4WK4tkYkOuv5rQrVS8aVrhYpe5y5VjuW637SmGCc5WgxJRsTUcqt8Z1IrUHLaGqJp5dlpsQ==" Feb 12 18:12:58 volumio volumio[19701]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=debug msg="completed keyexchange" Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=debug msg="completed challenge" Feb 12 18:12:58 volumio go-librespot[20066]: time="2026-02-12T18:12:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:12:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:12:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:12:58 volumio volumio[19701]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 18:12:59 volumio volumio[19701]: Error: socket hang up Feb 12 18:12:59 volumio volumio[19701]: at connResetException (node:internal/errors:720:14) Feb 12 18:12:59 volumio volumio[19701]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 18:12:59 volumio volumio[19701]: at Socket.emit (node:events:526:35) Feb 12 18:12:59 volumio volumio[19701]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 18:12:59 volumio volumio[19701]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 18:12:59 volumio volumio[19701]: code: 'ECONNRESET', Feb 12 18:12:59 volumio volumio[19701]: response: undefined Feb 12 18:12:59 volumio volumio[19701]: } Feb 12 18:12:59 volumio volumio[19701]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 18:13:00 volumio sudo[20087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 18:12' Feb 12 18:13:00 volumio sudo[20087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:00 volumio sudo[20087]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:02 volumio volumio-remote-updater[643]: [2026-02-12 18:13:02] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 12 18:13:02 volumio volumio-remote-updater[643]: [2026-02-12 18:13:02] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 12 18:13:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 18:13:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:02 volumio go-librespot[20096]: go-librespot daemon starting... Feb 12 18:13:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 18:13:02 volumio systemd[1]: volumio.service: Consumed 56.064s CPU time. Feb 12 18:13:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=debug msg="app state loaded" Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 18:13:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13550. Feb 12 18:13:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 18:13:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 18:13:02 volumio systemd[1]: volumio.service: Consumed 56.064s CPU time. Feb 12 18:13:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 18:13:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=info msg="zeroconf server listening on port 34287" Feb 12 18:13:02 volumio go-librespot[20098]: time="2026-02-12T18:13:02+07:00" level=debug msg="obtained new client token: AABYyL6y6uYDAWI/Ly/Nv3HO4qJc4BUHhAxMVF2Bl66OvvwZ1ix3+w/bgWN3E4liimxIXg5UVtNzEpuzhLpcckSBYZo5P9+g2cxrAEp8DmlUlBGjyvRfwPOJWEJtjj7kh9vFrJrvJgFCwVOv5+xVhB+Gg4fsUl6B9d5XfsOGslvwxy3DtEagfMf7dxZGxo/TfU7xjRpcx6OTFBeVsIqPRllVn++7BFHM7nRjYD1LVop34aTAYoh37lQ4SA==" Feb 12 18:13:03 volumio go-librespot[20098]: time="2026-02-12T18:13:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:03 volumio go-librespot[20098]: time="2026-02-12T18:13:03+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:03 volumio go-librespot[20098]: time="2026-02-12T18:13:03+07:00" level=debug msg="completed challenge" Feb 12 18:13:03 volumio go-librespot[20098]: time="2026-02-12T18:13:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:13:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:06 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:06 volumio volumio[20113]: info: ----- Volumio3 ---- Feb 12 18:13:06 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:06 volumio volumio[20113]: info: ----- System startup ---- Feb 12 18:13:06 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 18:13:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:06 volumio go-librespot[20134]: go-librespot daemon starting... Feb 12 18:13:06 volumio go-librespot[20135]: time="2026-02-12T18:13:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:06 volumio go-librespot[20135]: time="2026-02-12T18:13:06+07:00" level=debug msg="app state loaded" Feb 12 18:13:06 volumio go-librespot[20135]: time="2026-02-12T18:13:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:07 volumio volumio-remote-updater[643]: [2026-02-12 18:13:07] [connect] Successful connection Feb 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13: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 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13: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 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13: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 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13:07+07:00" level=info msg="zeroconf server listening on port 44213" Feb 12 18:13:07 volumio volumio[20113]: info: MYVOLUMIO Environment detected Feb 12 18:13:07 volumio volumio[20113]: info: Plugin folders cleanup Feb 12 18:13:07 volumio volumio[20113]: info: Scanning into folder /volumio/app/plugins/ Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category audio_interface Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category miscellanea Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category music_service Feb 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13:07+07:00" level=debug msg="obtained new client token: AACbRjdptIffCGDwJQqFD+ySGTRbAawKkR0e8d0tLnTG2rXRLm7IDItWInBZnq2IFm4SSj3DINM+m4Fnslia0KUSS4wQunfRYiGJj2kg6Bx9vxhArP5lOlr2dYZFyKz9XQilA/zthyRUQnYtd9AzrG9C7J1CZxfaqrZToqO1MiPD88Q1vYR8ZK8PnpJtyoCY7xVOQjBHbdeeASU9NHDB3XmpF1pDbF1ZwYQ8E9yJlAy6kxWiyr71Z+/O6g==" Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category plugins.json Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category system_controller Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category user_interface Feb 12 18:13:07 volumio volumio[20113]: info: Scanning into folder /data/plugins/ Feb 12 18:13:07 volumio volumio[20113]: info: Scanning category music_service Feb 12 18:13:07 volumio volumio[20113]: info: Plugin folders cleanup completed Feb 12 18:13:07 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:07 volumio volumio[20113]: info: ----- Core plugins startup ---- Feb 12 18:13:07 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:07 volumio volumio[20113]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 18:13:07 volumio volumio[20113]: info: Adding plugin upnp to MyMusic Plugins Feb 12 18:13:07 volumio volumio[20113]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 18:13:07 volumio volumio[20113]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 18:13:07 volumio volumio[20113]: info: Loading plugins from folder /data/plugins/ Feb 12 18:13:07 volumio volumio[20113]: info: Loading plugin "system"... Feb 12 18:13:07 volumio volumio[20113]: info: Loading plugin "appearance"... Feb 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13:07+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13:07+07:00" level=debug msg="completed challenge" Feb 12 18:13:07 volumio go-librespot[20135]: time="2026-02-12T18:13:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:13:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "network"... Feb 12 18:13:09 volumio volumio[20113]: info: Refreshing Cached IP Addresses Feb 12 18:13:09 volumio sudo[20150]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 18:13:09 volumio sudo[20150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:09 volumio sudo[20152]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 18:13:09 volumio sudo[20152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:09 volumio sudo[20150]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "services"... Feb 12 18:13:09 volumio sudo[20152]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "alsa_controller"... Feb 12 18:13:09 volumio sudo[20162]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 18:13:09 volumio sudo[20162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:09 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "wizard"... Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "networkfs"... Feb 12 18:13:09 volumio volumio[20113]: info: Starting Udev Watcher for removable devices Feb 12 18:13:09 volumio volumio[20113]: info: Ignoring mount for partition: boot Feb 12 18:13:09 volumio volumio[20113]: info: Ignoring mount for partition: volumio Feb 12 18:13:09 volumio volumio[20113]: info: Ignoring mount for partition: volumio_data Feb 12 18:13:09 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "volumio_command_line_client"... Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "upnp"... Feb 12 18:13:09 volumio volumio[20113]: info: [1770894789960] Starting Upmpd Daemon Feb 12 18:13:09 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "my_music"... Feb 12 18:13:09 volumio volumio[20113]: info: Loading plugin "mpd"... Feb 12 18:13:10 volumio volumio[20113]: info: Loading plugin "upnp_browser"... Feb 12 18:13:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 18:13:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:11 volumio go-librespot[20183]: go-librespot daemon starting... Feb 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+07:00" level=debug msg="app state loaded" Feb 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+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 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+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 12 18:13:11 volumio go-librespot[20184]: time="2026-02-12T18:13:11+07:00" level=info msg="zeroconf server listening on port 39541" Feb 12 18:13:12 volumio go-librespot[20184]: time="2026-02-12T18:13:12+07:00" level=debug msg="obtained new client token: AADp+ESje8Qz0l+jrI8qltbf193BliNMlJMxWeuLWVmiGUDdEKQpiX/I3jFvf6Od9XtmpeOzT04kGmzvooKiSuKwFDkFjkwa49WUA394nO+HjJnRBxX1kp+lt+/9WgKEYjrw4sKr6lbHwXCKP6TNe66r5skVtKmHpdNx9EZ+gwj2RU4kFo8VGuj/2sR93YCWqMFPB2kqxjxnLP+ax1L9YwSkvUvjUIelwsjE8tWArB0K7SXZBAn3m9wR9Q==" Feb 12 18:13:12 volumio go-librespot[20184]: time="2026-02-12T18:13:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:12 volumio go-librespot[20184]: time="2026-02-12T18:13:12+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:12 volumio go-librespot[20184]: time="2026-02-12T18:13:12+07:00" level=debug msg="completed challenge" Feb 12 18:13:12 volumio go-librespot[20184]: time="2026-02-12T18:13: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 12 18:13:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:12 volumio sudo[20162]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:13 volumio volumio[20113]: info: Starting UPNP Browser Feb 12 18:13:13 volumio volumio[20113]: info: Loading plugin "alarm-clock"... Feb 12 18:13:13 volumio volumio[20113]: info: Loading plugin "airplay_emulation"... Feb 12 18:13:13 volumio volumio[20113]: info: Starting Shairport Sync Feb 12 18:13:13 volumio volumio[20113]: info: Loading plugin "last_100"... Feb 12 18:13:13 volumio volumio[20113]: info: Loading plugin "webradio"... Feb 12 18:13:14 volumio volumio[20113]: info: Loading plugin "i2s_dacs"... Feb 12 18:13:14 volumio volumio[20113]: info: Loading plugin "volumiodiscovery"... Feb 12 18:13:14 volumio volumio[20113]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 18:13:14 volumio volumio[20113]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:13:14 volumio volumio[20113]: *** WARNING *** For more information see Feb 12 18:13:14 volumio volumio[20113]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 18:13:14 volumio volumio[20113]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:13:14 volumio volumio[20113]: *** WARNING *** For more information see Feb 12 18:13:14 volumio node[20113]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 18:13:14 volumio node[20113]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:13:14 volumio node[20113]: *** WARNING *** For more information see Feb 12 18:13:14 volumio node[20113]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 18:13:14 volumio node[20113]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 18:13:14 volumio node[20113]: *** WARNING *** For more information see Feb 12 18:13:14 volumio volumio[20113]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 18:13:14 volumio volumio[20113]: info: Discovery: Started advertising with name: Volumio Feb 12 18:13:14 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 18:13:14 volumio volumio[20113]: info: Loading plugin "spop"... Feb 12 18:13:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 18:13:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:15 volumio go-librespot[20195]: go-librespot daemon starting... Feb 12 18:13:15 volumio go-librespot[20196]: time="2026-02-12T18:13:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:15 volumio go-librespot[20196]: time="2026-02-12T18:13:15+07:00" level=debug msg="app state loaded" Feb 12 18:13:15 volumio go-librespot[20196]: time="2026-02-12T18:13:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:16 volumio volumio[20113]: info: Loading plugin "ytcr"... Feb 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13: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 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13: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 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13: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 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13:16+07:00" level=info msg="zeroconf server listening on port 33609" Feb 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13:16+07:00" level=debug msg="obtained new client token: AAB4b/guZx1Nuc6OFriIMxh+3noBBd7r7cuUwpp9mVOMVdKOBkq6n584Y2Mgi08MiFpyaLapJPhUGQoh99Md11sUEPb+i2ETToNARwIeS73Nq8oKpMc7uXV4V8wYKf1sOf99K+7ogtLYEg4p84yFnXs7SulkoN5q3h8RBnu6j2V45SA3Tk/d4SJsS+LFHQzxbUUfFQt7UwWQ+6hWr2NFrG6bBrqKMdTAH+cYxkIThradYUP1awGC0gaHeA==" Feb 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13:16+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:16 volumio go-librespot[20196]: time="2026-02-12T18:13:16+07:00" level=debug msg="completed challenge" Feb 12 18:13:17 volumio go-librespot[20196]: time="2026-02-12T18:13: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 12 18:13:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:18 volumio volumio[20113]: info: Loading plugin "ytmusic"... Feb 12 18:13:19 volumio volumio-remote-updater[643]: [2026-02-12 18:13:19] [connect] Successful connection Feb 12 18:13:19 volumio volumio[20113]: info: Loading plugin "outputs"... Feb 12 18:13:19 volumio volumio[20113]: info: Loading plugin "albumart"... Feb 12 18:13:19 volumio volumio[20113]: info: Plugin example_plugin is not enabled Feb 12 18:13:19 volumio volumio[20113]: info: Loading plugin "inputs"... Feb 12 18:13:19 volumio volumio[20113]: info: Loading plugin "updater_comm"... Feb 12 18:13:20 volumio volumio[20113]: info: Plugin mpdemulation is not enabled Feb 12 18:13:20 volumio volumio[20113]: info: Loading plugin "rest_api"... Feb 12 18:13:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 18:13:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:20 volumio volumio[20113]: info: Loading plugin "websocket"... Feb 12 18:13:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:20 volumio go-librespot[20227]: go-librespot daemon starting... Feb 12 18:13:20 volumio volumio[20113]: info: Starting Socket.io Server version 1.7.4 Feb 12 18:13:20 volumio volumio[20113]: info: Loading plugin "RoonBridge"... Feb 12 18:13:20 volumio go-librespot[20228]: time="2026-02-12T18:13:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:20 volumio go-librespot[20228]: time="2026-02-12T18:13:20+07:00" level=debug msg="app state loaded" Feb 12 18:13:20 volumio go-librespot[20228]: time="2026-02-12T18:13:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:20 volumio volumio[20113]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 18:13:20 volumio volumio[20113]: info: Loading i18n strings for locale en Feb 12 18:13:20 volumio volumio[20113]: Updating browse sources language Feb 12 18:13:20 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:13:21 volumio volumio[20217]: Forking 3 albumart workers Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+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 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+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 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+07:00" level=info msg="zeroconf server listening on port 42359" Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::initPlayerControls Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 18:13:21 volumio volumio[20113]: Express server listening on port 3000 Feb 12 18:13:21 volumio volumio[20113]: [Metrics] WebUI: 16s 173.89ms Feb 12 18:13:21 volumio volumio[20113]: info: CoreStateMachine::resetVolumioState Feb 12 18:13:21 volumio volumio[20113]: info: CoreStateMachine::getcurrentVolume Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+07:00" level=debug msg="obtained new client token: AAB9qj3ntZE4chczCriPPv7ZUbB01qcI7JTNOnEWg656h4Evi/WAFZhr4zcm3NCWpHSyb+fYEhHuGgTi1BHopAZprcyX5nQ5KEoUrbcLmMaMaDbQHcOi2Hy6x0l1DD8BNP4n6Hyuolqj+ZAfYE6dCLIdG19o6naYsBYlJ93hqqAd8BKkCCZOzs38PsQNOXjgp8a9EuOFGFzVDUOpeSxce4qnNSmsMreIJsse8zoVqgeri0W+HfkeXlnOqQ==" Feb 12 18:13:21 volumio sudo[20270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 18:13:21 volumio sudo[20270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:21 volumio sudo[20272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 18:13:21 volumio sudo[20272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:21 volumio sudo[20270]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:21 volumio sudo[20272]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:21 volumio volumio[20113]: info: Volumio Network Manager: Network status updated: 1 Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13:21+07:00" level=debug msg="completed challenge" Feb 12 18:13:21 volumio volumio[20113]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:13:21 volumio volumio[20113]: info: CoreStateMachine::pushState Feb 12 18:13:21 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::volumioPushState Feb 12 18:13:21 volumio go-librespot[20228]: time="2026-02-12T18:13: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 12 18:13:21 volumio volumio[20113]: info: CoreStateMachine::updateTrackBlock Feb 12 18:13:21 volumio volumio[20113]: info: CorePlayQueue::getTrackBlock Feb 12 18:13:21 volumio volumio[20113]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:13:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:21 volumio volumio-remote-updater[643]: [2026-02-12 18:13:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770894799 101 Feb 12 18:13:22 volumio volumio[20113]: 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 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:22 volumio volumio[20113]: info: Reloading queue from file Feb 12 18:13:22 volumio volumio[20113]: info: CoreStateMachine::setRepeat null single undefined Feb 12 18:13:22 volumio volumio[20113]: info: CoreStateMachine::pushState Feb 12 18:13:22 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::volumioPushState Feb 12 18:13:22 volumio volumio[20113]: info: CoreStateMachine::setRandom null Feb 12 18:13:22 volumio volumio[20113]: info: CoreStateMachine::pushState Feb 12 18:13:22 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::volumioPushState Feb 12 18:13:22 volumio volumio[20113]: info: Setting Device type: Raspberry PI Feb 12 18:13:22 volumio volumio[20113]: info: Completed loading Core Plugins Feb 12 18:13:22 volumio volumio[20113]: info: Preparing to generate the ALSA configuration file Feb 12 18:13:22 volumio volumio[20113]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:13:22 volumio volumio[20113]: info: CoreStateMachine::pushState Feb 12 18:13:22 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::volumioPushState Feb 12 18:13:22 volumio volumio[20113]: info: Asound.conf file unchanged, so no further update is needed Feb 12 18:13:22 volumio volumio[20113]: info: Output device has changed, restarting MPD Feb 12 18:13:22 volumio sudo[20288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 18:13:22 volumio sudo[20288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:22 volumio volumio[20113]: info: Output device has changed, restarting Shairport Sync Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:22 volumio sudo[20288]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:22 volumio sudo[20291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 18:13:22 volumio sudo[20293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 18:13:22 volumio sudo[20293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:22 volumio volumio[20113]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 18:13:22 volumio volumio[20113]: info: ___________ START PLUGINS ___________ Feb 12 18:13:22 volumio sudo[20291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:22 volumio sudo[20291]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:22 volumio volumio[20113]: info: ControllerMpd::onStart: Initializing MPD Feb 12 18:13:22 volumio volumio[20113]: info: Creating MPD Configuration file Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 18:13:22 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:13:22 volumio volumio[20113]: info: [1770894802713] CoreMusicLibrary::Adding element Media Servers Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:13:22 volumio sudo[20303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 18:13:22 volumio sudo[20303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:22 volumio sudo[20301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 18:13:22 volumio volumio[20113]: info: UPNP Browser: Client initialized successfully Feb 12 18:13:22 volumio sudo[20301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:22 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 18:13:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 18:13:22 volumio systemd[1]: mpd.service: Consumed 7.164s CPU time. Feb 12 18:13:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 18:13:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 18:13:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 18:13:22 volumio sudo[20301]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:22 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 18:13:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 18:13:23 volumio volumio[20113]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:23 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 18:13:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 18:13:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 18:13:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 18:13:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 18:13:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 18:13:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 18:13:23 volumio volumio[20113]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:13:23 volumio volumio[20113]: info: [1770894803173] CoreMusicLibrary::Adding element Last_100 Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:13:23 volumio volumio[20113]: info: [1770894803194] CoreMusicLibrary::Adding element Webradio Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 18:13:23 volumio volumio[20113]: info: Initializing BBC Radios Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:23 volumio volumio[20113]: info: Creating Spotify config file Feb 12 18:13:23 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:23 volumio sudo[20317]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 18:13:23 volumio sudo[20317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 18:13:23 volumio sudo[20317]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:24 volumio volumio[20236]: Starting albumart workers Feb 12 18:13:24 volumio volumio[20237]: Starting albumart workers Feb 12 18:13:24 volumio volumio[20235]: Starting albumart workers Feb 12 18:13:24 volumio volumio[20113]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:13:24 volumio volumio[20113]: info: [1770894804685] CoreMusicLibrary::Adding element YouTube Music Feb 12 18:13:24 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:13:24 volumio volumio[20113]: Cannot find translation for source YouTube Music Feb 12 18:13:24 volumio volumio[20113]: info: Volumio Calling Home Feb 12 18:13:24 volumio sudo[20334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 18:13:24 volumio sudo[20334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 12 18:13:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:25 volumio go-librespot[20339]: go-librespot daemon starting... Feb 12 18:13:25 volumio go-librespot[20340]: time="2026-02-12T18:13:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:25 volumio sudo[20334]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:25 volumio go-librespot[20340]: time="2026-02-12T18:13:25+07:00" level=info msg="zeroconf server listening on port 41899" Feb 12 18:13:25 volumio volumio[20113]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 18:13:26 volumio volumio[20113]: info: Discovery: Found device Volumio Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::volumioGetState Feb 12 18:13:26 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:26 volumio volumio[20113]: info: MPD Permissions set Feb 12 18:13:26 volumio volumio[20113]: info: MPD Permissions set Feb 12 18:13:26 volumio volumio[20113]: info: Upmpdcli Daemon Started Feb 12 18:13:26 volumio volumio[20113]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 18:13:26 volumio volumio[20113]: info: Discovery: Found device Volumio Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::volumioGetState Feb 12 18:13:26 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:26 volumio volumio[20113]: info: Volumio called home Feb 12 18:13:26 volumio volumio[20113]: info: Spotify config file written Feb 12 18:13:26 volumio volumio[20113]: 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 12 18:13:26 volumio sudo[20352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 18:13:26 volumio sudo[20352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 18:13:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 18:13:26 volumio volumio[20113]: info: No need to fix Spotify hosts Feb 12 18:13:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:26 volumio go-librespot[20362]: go-librespot daemon starting... Feb 12 18:13:26 volumio sudo[20352]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:26 volumio go-librespot[20368]: time="2026-02-12T18:13:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:26 volumio go-librespot[20368]: time="2026-02-12T18:13:26+07:00" level=debug msg="app state loaded" Feb 12 18:13:26 volumio go-librespot[20368]: time="2026-02-12T18:13:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:27 volumio go-librespot[20368]: time="2026-02-12T18:13:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 18:13:27 volumio go-librespot[20368]: time="2026-02-12T18:13:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 18:13:27 volumio go-librespot[20368]: time="2026-02-12T18:13:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 18:13:27 volumio go-librespot[20368]: time="2026-02-12T18:13:27+07:00" level=info msg="zeroconf server listening on port 39679" Feb 12 18:13:27 volumio volumio[20113]: info: Starting Shairport Sync Feb 12 18:13:27 volumio volumio[20113]: info: Starting Shairport Sync Feb 12 18:13:27 volumio volumio[20113]: info: Starting Shairport Sync Feb 12 18:13:27 volumio sudo[20388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:13:27 volumio sudo[20388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:27 volumio sudo[20390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:13:27 volumio sudo[20390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:27 volumio sudo[20392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 18:13:27 volumio sudo[20392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 18:13:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 18:13:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:13:27 volumio systemd[1]: shairport-sync.service: Consumed 2.354s CPU time. Feb 12 18:13:27 volumio go-librespot[20368]: time="2026-02-12T18:13:27+07:00" level=debug msg="obtained new client token: AAAOXesXKXz7MGV4DRAjylMtfVU6dBTmSyCXBrfj358fPBnJTmWIWaR9WCQIqnDikr/PXOAYYDTrpFw/VXnjmGQlkSMeP6S1CTnmBt0nCS2bqQ+fxngzaoTP5Ok9BE9deRwdv8vBv4/SST1ku22fHf2xqWaReqZsdSepe5WA3tLAzON8+j3hMsSxw9qtSWRp7MI56CCk6RVDG92ZOsktsuvUV3Vb9ch7WL5Cs3G4p4qktT1yUy1pVMS2ow==" Feb 12 18:13:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:13:27 volumio sudo[20388]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:27 volumio go-librespot[20368]: time="2026-02-12T18:13:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:27 volumio sudo[20390]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 18:13:27 volumio volumio[20113]: info: Shairport-Sync Started Feb 12 18:13:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 18:13:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:13:27 volumio volumio[20113]: Error adding Membership: Error: addMembership EINVAL Feb 12 18:13:27 volumio volumio[20113]: info: Shairport-Sync Started Feb 12 18:13:28 volumio volumio[20113]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 18:13:28 volumio volumio[20113]: SPOTIFY: BQD6ioHMLaLKh4hF2ZACSEXvXGgR9ujOD1clppOHXZWttmsjhJtrF6yJroEdFzJQO_o5kSeKnksFvPhkWpyFYETAFbIc1L6V6WAXHqKphcQA1mZizADRlw2k24ZdClNOfORQWE2VhLON3tjVCe1bh7dZqVaBFMg0MoC7a-E0bp7QiMcrUOP1R_v8m81xSx2dSIsIuVjhl3F_WbEt67cbJRyZS7K1eC7O4pwAUwAGNBZw7z8lhekwgUFtOpsYDANFKHaoS6bwDBycQkZzg-YKo1OUUh6R5Tg_W2SzuZhdkJC6f42WQ1LyeS-p Feb 12 18:13:28 volumio volumio[20113]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 18:13:28 volumio volumio[20113]: info: New Spotify access token = BQD6ioHMLaLKh4hF2ZACSEXvXGgR9ujOD1clppOHXZWttmsjhJtrF6yJroEdFzJQO_o5kSeKnksFvPhkWpyFYETAFbIc1L6V6WAXHqKphcQA1mZizADRlw2k24ZdClNOfORQWE2VhLON3tjVCe1bh7dZqVaBFMg0MoC7a-E0bp7QiMcrUOP1R_v8m81xSx2dSIsIuVjhl3F_WbEt67cbJRyZS7K1eC7O4pwAUwAGNBZw7z8lhekwgUFtOpsYDANFKHaoS6bwDBycQkZzg-YKo1OUUh6R5Tg_W2SzuZhdkJC6f42WQ1LyeS-p Feb 12 18:13:28 volumio volumio[20113]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 18:13:28 volumio go-librespot[20368]: time="2026-02-12T18:13:28+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:28 volumio go-librespot[20368]: time="2026-02-12T18:13:28+07:00" level=debug msg="completed challenge" Feb 12 18:13:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 18:13:28 volumio sudo[20392]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:28 volumio volumio[20113]: info: CoreCommandRouter::volumioGetState Feb 12 18:13:28 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:28 volumio volumio[20113]: info: Shairport-Sync Started Feb 12 18:13:28 volumio go-librespot[20368]: time="2026-02-12T18:13:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:13:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:28 volumio volumio[20113]: 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 12 18:13:28 volumio volumio[20113]: info: Spotify Successfully logged in Feb 12 18:13:28 volumio volumio[20113]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 18:13:28 volumio volumio[20113]: info: [1770894808480] CoreMusicLibrary::Adding element Spotify Feb 12 18:13:28 volumio volumio[20113]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 18:13:28 volumio volumio[20113]: Cannot find translation for source YouTube Music Feb 12 18:13:28 volumio volumio[20113]: Cannot find translation for source Spotify Feb 12 18:13:28 volumio volumio[20113]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 18:13:28 volumio volumio[20113]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 18:13:29 volumio volumio[20113]: info: VolumeController:: Volume=100 Mute =false Feb 12 18:13:29 volumio volumio[20113]: info: CoreCommandRouter::volumioGetState Feb 12 18:13:29 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:29 volumio volumio[20113]: info: CoreStateMachine::pushState Feb 12 18:13:29 volumio volumio[20113]: info: CorePlayQueue::getTrack 0 Feb 12 18:13:29 volumio volumio[20113]: info: CoreCommandRouter::volumioPushState Feb 12 18:13:30 volumio volumio[20113]: info: go-librespot daemon successfully initialized Feb 12 18:13:30 volumio mpd[20332]: 2026-02-12T18:13:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 18:13:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 18:13:30 volumio sudo[20303]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:30 volumio sudo[20293]: pam_unix(sudo:session): session closed for user root Feb 12 18:13:30 volumio volumio[20113]: error: MPD error: The expression evaluated to a falsy value: Feb 12 18:13:30 volumio volumio[20113]: assert.ok(self.idling) Feb 12 18:13:30 volumio volumio[20113]: error: The expression evaluated to a falsy value: Feb 12 18:13:30 volumio volumio[20113]: assert.ok(self.idling) Feb 12 18:13:30 volumio volumio[20113]: info: MPD running with PID20332 Feb 12 18:13:30 volumio volumio[20113]: ,establishing connection Feb 12 18:13:30 volumio volumio[20113]: error: updateQueue error: null Feb 12 18:13:30 volumio volumio[20113]: info: Completed starting Core Plugins Feb 12 18:13:30 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:30 volumio volumio[20113]: info: ----- MyVolumio plugins startup ---- Feb 12 18:13:30 volumio volumio[20113]: info: ------------------------------------------- Feb 12 18:13:30 volumio volumio[20113]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 18:13:30 volumio volumio[20113]: error: updateQueue error: null Feb 12 18:13:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 18:13:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:31 volumio go-librespot[20434]: go-librespot daemon starting... Feb 12 18:13:31 volumio go-librespot[20435]: time="2026-02-12T18:13:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:31 volumio go-librespot[20435]: time="2026-02-12T18:13:31+07:00" level=debug msg="app state loaded" Feb 12 18:13:31 volumio go-librespot[20435]: time="2026-02-12T18:13:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:31 volumio go-librespot[20435]: time="2026-02-12T18:13:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:13:31 volumio go-librespot[20435]: time="2026-02-12T18:13:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 18:13:31 volumio go-librespot[20435]: time="2026-02-12T18:13:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 18:13:32 volumio go-librespot[20435]: time="2026-02-12T18:13:32+07:00" level=info msg="zeroconf server listening on port 46811" Feb 12 18:13:32 volumio go-librespot[20435]: time="2026-02-12T18:13:32+07:00" level=debug msg="obtained new client token: AAA2Wg7hLphBgbtE0dnr7yttbtvTOOo/v9IXW6Ys6QnqZO78197dDqW8SGOKkzQsQnKPRKPmPDydXWBcagGdllvXrCzjldyxPnsMIbTpqBnqdQj9RHx/m3uWWPguMY5yqVqDCiO8SCXLLLr4xmm5rpfznqHH07sql/EttTgn69yebkygkUAx4IMnnnsXSnKDtqN/7boT1kvbLSmJdyQfwhymgk5ykE7CXhIlsYNgoZLzquZf5e9yeBY=" Feb 12 18:13:32 volumio go-librespot[20435]: time="2026-02-12T18:13:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:32 volumio go-librespot[20435]: time="2026-02-12T18:13:32+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:32 volumio go-librespot[20435]: time="2026-02-12T18:13:32+07:00" level=debug msg="completed challenge" Feb 12 18:13:32 volumio go-librespot[20435]: time="2026-02-12T18:13:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:13:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:33 volumio volumio[20113]: info: Initializing connection to go-librespot Websocket Feb 12 18:13:33 volumio volumio[20113]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 18:13:35 volumio volumio[20113]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 18:13:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 18:13:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:35 volumio go-librespot[20444]: go-librespot daemon starting... Feb 12 18:13:35 volumio go-librespot[20445]: time="2026-02-12T18:13:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:35 volumio go-librespot[20445]: time="2026-02-12T18:13:35+07:00" level=debug msg="app state loaded" Feb 12 18:13:35 volumio go-librespot[20445]: time="2026-02-12T18:13:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:36 volumio volumio[20113]: info: Initializing connection to go-librespot Websocket Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=debug msg="new websocket client" Feb 12 18:13:36 volumio volumio[20113]: info: Connection to go-librespot Websocket established Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+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 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+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 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=info msg="zeroconf server listening on port 44679" Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=debug msg="obtained new client token: AACxEwsOUDIX9NS3KqlXy6E3EV6+340GBdrxLm7y6pyWdwVZwX9RlMZ+uJFfvCEGrrRhTyok4whaXPFSGPLx0GRaTEDShIzS90m+HsMd1KuEbuhcoTvIs1gk3OFMvLXbI2T/RUd9zPwk333YK7UsryszMZb6mGqNVYPT+utsorPdULn6KZXNdTYkIHpDwPRE7Rv1NEGhROXnNp9oJolw8FyROzpE3OmKjgsfR7xhcyZtrA+xDnCI/LltWQ==" Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:36 volumio go-librespot[20445]: time="2026-02-12T18:13:36+07:00" level=debug msg="completed challenge" Feb 12 18:13:37 volumio go-librespot[20445]: time="2026-02-12T18:13:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 18:13:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 18:13:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 18:13:37 volumio volumio[20113]: info: Connection to go-librespot Websocket closed Feb 12 18:13:39 volumio volumio[20113]: info: Getting Spotify volume Feb 12 18:13:39 volumio volumio[20113]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 18:13:39 volumio volumio[20113]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 18:13:39 volumio volumio[20113]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 18:13:39 volumio volumio[20113]: errno: -111, Feb 12 18:13:39 volumio volumio[20113]: code: 'ECONNREFUSED', Feb 12 18:13:39 volumio volumio[20113]: syscall: 'connect', Feb 12 18:13:39 volumio volumio[20113]: address: '127.0.0.1', Feb 12 18:13:39 volumio volumio[20113]: port: 9879, Feb 12 18:13:39 volumio volumio[20113]: response: undefined Feb 12 18:13:39 volumio volumio[20113]: } Feb 12 18:13:39 volumio volumio[20113]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 18:13:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 18:13:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 18:13:40 volumio go-librespot[20478]: go-librespot daemon starting... Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=debug msg="app state loaded" Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 18:13:40 volumio go-librespot[20479]: time="2026-02-12T18:13:40+07:00" level=info msg="zeroconf server listening on port 46655" Feb 12 18:13:40 volumio sudo[20488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 18:12' Feb 12 18:13:40 volumio sudo[20488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 18:13:41 volumio go-librespot[20479]: time="2026-02-12T18:13:41+07:00" level=debug msg="obtained new client token: AAB/VntQCWlJoLA5pSIybElsT0mXRsNfFdEBN7G/L4SmuK2IWkPYHhIPo5QFkWlQ1PqfpJXWBFAV3SJSmIFi4l+ovRQER0FioVn6UGUvbITJX2WzlBhGqli/iAjAZqKxPqFJDA34bfDLYrI1IiaznuXOLY21QdI50t5La3nwbl6fq666LV1sMutYw9EuC0NinuFUD1ZLpmyA1fYEZUW56QAUVHM5Hq1ZZ2yMRa2Xn8yDJEaxpm1Dj1M=" Feb 12 18:13:41 volumio go-librespot[20479]: time="2026-02-12T18:13:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 18:13:41 volumio go-librespot[20479]: time="2026-02-12T18:13:41+07:00" level=debug msg="completed keyexchange" Feb 12 18:13:41 volumio go-librespot[20479]: time="2026-02-12T18:13:41+07:00" level=debug msg="completed challenge" 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"