-- Logs begin at Sat 2025-05-31 20:12:45 UTC, end at Sun 2025-06-01 15:06:45 UTC. -- Jun 01 15:05:00 volumio go-librespot[1527]: time="2025-06-01T15:05:00Z" level=info msg="zeroconf server listening on port 46391" Jun 01 15:05:00 volumio go-librespot[1527]: time="2025-06-01T15:05:00Z" level=debug msg="obtained new client token: AABHqmiFjZl1BGG6aL1gxruVa4zJgNGRixJ9IsizeQgUD9q5FFZSm6h1TKwBvhCXykRcg0iAkQyqK4tl3r+Hq3nmXgaxggHXuuDYtPsTQogLMTEYP1iAA60410Tfq42wxNktm3rMjQawb1F6krRi5snM2cBEkrpsYKjj1GcT4rtzYcD73ZDlxHt2u7LX2o7kRC/m49ORSECm53uK672zWGVQamUUfs5t9XytTBnFgmg+o7pnxuuO" Jun 01 15:05:00 volumio go-librespot[1527]: time="2025-06-01T15:05:00Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:00 volumio go-librespot[1527]: time="2025-06-01T15:05:00Z" level=debug msg="completed keyexchange" Jun 01 15:05:00 volumio go-librespot[1527]: time="2025-06-01T15:05:00Z" level=debug msg="completed challenge" Jun 01 15:05:00 volumio go-librespot[1527]: time="2025-06-01T15:05:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:02 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:02 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Jun 01 15:05:03 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:03 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:03 volumio go-librespot[1535]: go-librespot daemon starting... Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="app state loaded" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="stored credentials not found" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=info msg="zeroconf server listening on port 33069" Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="obtained new client token: AAAUOVkijH46ar9UpbxV8IWfluVMMcO6s14KS2omLUBVbPLEYdWtBpKj+o41GULVV6NxtHt59UTmosqHcey2ERNgcXbHNef1FLHMqm3b4q7cBWF4PSh8fVskHEd+6IqjwF4IoszXMPr0d1gkjoPnZfnFkiXaTugts3VMX5qNxkmiUaNh/0ZSqm8iN/tLpcfo3FZOyVqi26nvoXVMFym9NQnblaNLuBCGHcqoKh/JzKAw0fWTNmIQkGM=" Jun 01 15:05:03 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 15:05:03 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 15:05:03 volumio volumio[813]: info: Discovery: Getting this device information Jun 01 15:05:03 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:03 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:03 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 15:05:03 volumio go-librespot[1535]: time="2025-06-01T15:05:03Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:04 volumio go-librespot[1535]: time="2025-06-01T15:05:04Z" level=debug msg="completed keyexchange" Jun 01 15:05:04 volumio go-librespot[1535]: time="2025-06-01T15:05:04Z" level=debug msg="completed challenge" Jun 01 15:05:04 volumio volumio[813]: verbose: New Socket.io Connection to 192.168.178.28 from 192.168.178.177 UA: okhttp/3.12.12 Total Clients: 6 Jun 01 15:05:04 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:04 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:04 volumio go-librespot[1535]: time="2025-06-01T15:05:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:04 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 01 15:05:04 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 01 15:05:06 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:06 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:06 volumio sudo[1545]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 01 15:05:06 volumio sudo[1545]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:06 volumio sudo[1545]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:06 volumio sudo[1548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 01 15:05:06 volumio sudo[1548]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:06 volumio sudo[1548]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:06 volumio volumio[813]: verbose: New Socket.io Connection to 192.168.178.28 from 192.168.178.177 UA: okhttp/3.12.12 Total Clients: 7 Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::volumioGetVisibleSources Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:06 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 01 15:05:06 volumio volumio[813]: info: Received Get System Info Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 15:05:06 volumio volumio[813]: info: Discovery: Getting this device information Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:06 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:06 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:06 volumio volumio[813]: info: Listing playlists Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 01 15:05:06 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 01 15:05:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Jun 01 15:05:07 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:07 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:07 volumio go-librespot[1550]: go-librespot daemon starting... Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="app state loaded" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="stored credentials not found" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=info msg="zeroconf server listening on port 34095" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="obtained new client token: AABdEe2MchTZ9v8z+nA/lO0jVFpT0epO8EYWex2OoOcZcDl8X1SJz0n3BSP4VSOqVGEotUdPvEQBjEMyYjgN+FTYE9eWrfdOd+Z4PGHqsW7ZeaYNlvqwtVDQWqbKhkNR0dSNzSU0q0XsWECaXOqeOXU+fz/nN53Nby8HAG7LNw836d7L7SSfJcfgz/SF6B6snGku7Ad4U52nD0UxIrmXyKbUqlJw/MEC5Kqitv+BibHJLe75FD24qPg=" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="completed keyexchange" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=debug msg="completed challenge" Jun 01 15:05:07 volumio go-librespot[1550]: time="2025-06-01T15:05:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:08 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 15:05:08 volumio volumio[813]: info: Received Get System Info Jun 01 15:05:08 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 15:05:08 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 15:05:08 volumio volumio[813]: info: Discovery: Getting this device information Jun 01 15:05:08 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:08 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:08 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 15:05:09 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:09 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 15:05:10 volumio volumio[813]: info: Received Get System Info Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 15:05:10 volumio volumio[813]: info: Discovery: Getting this device information Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:10 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jun 01 15:05:10 volumio sudo[1561]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jun 01 15:05:10 volumio sudo[1561]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:10 volumio sudo[1561]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:10 volumio sudo[1567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jun 01 15:05:10 volumio sudo[1567]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:10 volumio sudo[1567]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:10 volumio sudo[1575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jun 01 15:05:10 volumio sudo[1575]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:10 volumio sudo[1575]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:10 volumio sudo[1581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jun 01 15:05:10 volumio sudo[1581]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:10 volumio sudo[1581]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:10 volumio sudo[1587]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 01 15:05:10 volumio sudo[1587]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:10 volumio sudo[1587]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Jun 01 15:05:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Jun 01 15:05:10 volumio sudo[1591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 01 15:05:10 volumio sudo[1591]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 15:05:10 volumio sudo[1591]: pam_unix(sudo:session): session closed for user root Jun 01 15:05:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Jun 01 15:05:10 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:10 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:10 volumio go-librespot[1593]: go-librespot daemon starting... Jun 01 15:05:10 volumio go-librespot[1593]: time="2025-06-01T15:05:10Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:10 volumio go-librespot[1593]: time="2025-06-01T15:05:10Z" level=debug msg="app state loaded" Jun 01 15:05:10 volumio go-librespot[1593]: time="2025-06-01T15:05:10Z" level=debug msg="stored credentials not found" Jun 01 15:05:10 volumio go-librespot[1593]: time="2025-06-01T15:05:10Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=info msg="zeroconf server listening on port 32771" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="obtained new client token: AACgdKDxEd5cbzUlfFoB0ghie+EWQJ2KFFl8k17qrhiwccnWjb2Qe4K9Cu4z8CvpfEmb2tVVS6WJqt5e7mZAud4FiyurIf+fpfy+x4R5CjzTrbVSFrllpItjlAs1MpkstlRRcOTwWW82nGDtnuOIdMhXhsaD2EGv1CClTA1wRJvAixroyVeCtskPdlv5Vc2KY2QduKkZl9drcf0gDhXrjLlPt7Rgom1VmaciQQVE2S0ojZQ+wQzmNqE=" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="completed keyexchange" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=debug msg="completed challenge" Jun 01 15:05:11 volumio go-librespot[1593]: time="2025-06-01T15:05:11Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:12 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:12 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Jun 01 15:05:14 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:14 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:14 volumio go-librespot[1601]: go-librespot daemon starting... Jun 01 15:05:14 volumio go-librespot[1601]: time="2025-06-01T15:05:14Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:14 volumio go-librespot[1601]: time="2025-06-01T15:05:14Z" level=debug msg="app state loaded" Jun 01 15:05:14 volumio go-librespot[1601]: time="2025-06-01T15:05:14Z" level=debug msg="stored credentials not found" Jun 01 15:05:14 volumio go-librespot[1601]: time="2025-06-01T15:05:14Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:15 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:15 volumio volumio[813]: info: Connection to go-librespot Websocket established Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="new websocket client" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=info msg="zeroconf server listening on port 46253" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="obtained new client token: AABCtpM7YWWz4BgXD7ZvKFCwUX7fOkF3TZUC7OTBI4XXFBGnVUBnQ9PG5YDdDg5ak10UZa96n+qVAq3yFb4ksvHzibK9ZBCMtMWRyhijMWgwtxIB7g9bs/eLy+o0ViIMrAIRceFr2goUkmPopv7SHRDDPZ3g5jMjVNhii6qsPmi/q4+aHcgWbx7wTF0+BZ/P/H/e41i4Ynv/zDun9puAaL0Gj9Ctxua2L2prlpgopDKKg+486t1dFNU=" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="completed keyexchange" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=debug msg="completed challenge" Jun 01 15:05:15 volumio go-librespot[1601]: time="2025-06-01T15:05:15Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:15 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jun 01 15:05:18 volumio volumio[813]: info: Getting Spotify volume Jun 01 15:05:18 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:18 volumio volumio[813]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 01 15:05:18 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 9) Jun 01 15:05:18 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Jun 01 15:05:18 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:18 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:18 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Jun 01 15:05:18 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:18 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:18 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:18 volumio go-librespot[1609]: go-librespot daemon starting... Jun 01 15:05:18 volumio go-librespot[1609]: time="2025-06-01T15:05:18Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:18 volumio go-librespot[1609]: time="2025-06-01T15:05:18Z" level=debug msg="app state loaded" Jun 01 15:05:18 volumio go-librespot[1609]: time="2025-06-01T15:05:18Z" level=debug msg="stored credentials not found" Jun 01 15:05:18 volumio go-librespot[1609]: time="2025-06-01T15:05:18Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=info msg="zeroconf server listening on port 32935" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="obtained new client token: AAC5IAJe/GXd+ooUlyhBjMr41f5nFskiN6qPcegstUP9G++SM44eSDQnlAMv/kD1ND/mR/ZKFVtECJ59OodPn25eStSf6pnJRZaeTiyfeiTw+93G0VWfJC3JVHM6ZU1jCU4JaToZzwcpeDJ8Cs8zboOmAfNmP60+/Hg2wvO+EgK8FcyHaOYwBV5SCZfnkCGQx9G5GhbPLS5E91KTz7/onfBGCcYuhbMHK54yA/Cc+4KXho4f8y6u" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="completed keyexchange" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=debug msg="completed challenge" Jun 01 15:05:19 volumio go-librespot[1609]: time="2025-06-01T15:05:19Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:21 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:21 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Jun 01 15:05:22 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:22 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:22 volumio go-librespot[1617]: go-librespot daemon starting... Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=debug msg="app state loaded" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=debug msg="stored credentials not found" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=info msg="zeroconf server listening on port 36231" Jun 01 15:05:22 volumio go-librespot[1617]: time="2025-06-01T15:05:22Z" level=debug msg="obtained new client token: AABc76geuELP5qgo1jhUvvWqmF69vqbSY6i29TxbQGF8cnvcVDhhiC+D+j21UFdoYJNR9ppuslN6Gq8pCabdeNsWlFuPfbGn1Oj2vZ+RGccQj2QhaKZ4BLf6o1w11gJcXs4o+MWCia6h3ouozVbhrAykFfth7foEYhBgs8UhnePoGziVB5sEK43Vs+5fMmY4Or3tlhAHR6m8fXsjQKYY4kKP/zJsNo4HcC+0mPVdE/qxyYVKUEVOA0Y=" Jun 01 15:05:23 volumio go-librespot[1617]: time="2025-06-01T15:05:23Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:23 volumio go-librespot[1617]: time="2025-06-01T15:05:23Z" level=debug msg="completed keyexchange" Jun 01 15:05:23 volumio go-librespot[1617]: time="2025-06-01T15:05:23Z" level=debug msg="completed challenge" Jun 01 15:05:23 volumio go-librespot[1617]: time="2025-06-01T15:05:23Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:24 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:24 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 01 15:05:24 volumio volumio[813]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 01 15:05:24 volumio volumio[813]: info: Received Get System Version Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 15:05:24 volumio volumio[813]: info: Received Get System Info Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 15:05:24 volumio volumio[813]: info: Discovery: Getting this device information Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:24 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:24 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 15:05:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Jun 01 15:05:26 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:26 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:26 volumio go-librespot[1625]: go-librespot daemon starting... Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="app state loaded" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="stored credentials not found" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=info msg="zeroconf server listening on port 41795" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="obtained new client token: AADCgJhMi3Go5/NKTu5WGqxe8z35KsHoIwYVOZxu/SpZAEdGqkV/prJjOJlc/RfnOw2xUTr+HL3/rsaJj4iv9eBxE7dZe5yPdZiYM2rmWlt77nGJFlfglv/eOw9cbKg11A8is7UcIc9yHaeTdXSV9KetbXMqMcQKJaS1sT3J76u6TQuMt7rQiavWzc02wz5CIGtEzxthCffMT6Fc81v5r8TjW/gw2PCBTKNsuSS/ANWQx6zRG67Cvcc=" Jun 01 15:05:26 volumio go-librespot[1625]: time="2025-06-01T15:05:26Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:27 volumio go-librespot[1625]: time="2025-06-01T15:05:27Z" level=debug msg="completed keyexchange" Jun 01 15:05:27 volumio go-librespot[1625]: time="2025-06-01T15:05:27Z" level=debug msg="completed challenge" Jun 01 15:05:27 volumio go-librespot[1625]: time="2025-06-01T15:05:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:27 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:27 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Jun 01 15:05:30 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:30 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:30 volumio go-librespot[1633]: go-librespot daemon starting... Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="app state loaded" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="stored credentials not found" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=info msg="zeroconf server listening on port 37953" Jun 01 15:05:30 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="new websocket client" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="obtained new client token: AABcljPrbh9NSoYUyTr3APg5YOrlQlOhmnPKilSH5+yJfvhBj+LoU4aOlHKZi4QEt4OygF+R6KRfyB53HloeQx0A2V6x+xXtTb15aI9InUuJifiJcScCcndtgTiUmeu+nuXHqUH3W6mFvRFHqTaiZPCBp+tidwjITRWNql9m4HLjBzqGPBtKRMzskxWd9qMskpWF+AOkq8WaSI0Xw8QzG07G5izcKj0SWgo9OnmMOh1dh/W7rCfRzFs=" Jun 01 15:05:30 volumio volumio[813]: info: Connection to go-librespot Websocket established Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="completed keyexchange" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=debug msg="completed challenge" Jun 01 15:05:30 volumio go-librespot[1633]: time="2025-06-01T15:05:30Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:30 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jun 01 15:05:33 volumio volumio[813]: info: Getting Spotify volume Jun 01 15:05:33 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:33 volumio volumio[813]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 01 15:05:33 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 10) Jun 01 15:05:33 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Jun 01 15:05:33 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:33 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:33 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:33 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Jun 01 15:05:33 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:33 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:33 volumio go-librespot[1642]: go-librespot daemon starting... Jun 01 15:05:33 volumio go-librespot[1642]: time="2025-06-01T15:05:33Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:33 volumio go-librespot[1642]: time="2025-06-01T15:05:33Z" level=debug msg="app state loaded" Jun 01 15:05:33 volumio go-librespot[1642]: time="2025-06-01T15:05:33Z" level=debug msg="stored credentials not found" Jun 01 15:05:33 volumio go-librespot[1642]: time="2025-06-01T15:05:33Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:34 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:34 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=info msg="zeroconf server listening on port 33843" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="obtained new client token: AAC8y/Ub0gArc7L4IfUtNi/XjFN1ztyDf6G8cJgoSuCOa2BK4knoxgnvn7aC9EIYXBRXt7ANoANBoONWBCNLXDJzDvfTHQrGVnzo0wC/bvM+KBtAXKnCaw9JRrkoFBpzZ4XaIWfzhzW2mCE3zZq/pxAmBm1tw36WMMFncb58U4sBKhkXMX8EBnilCXkTwGUpjpo0Fg4Zj22XfWbU2/adwU1C0XQjMHGrV1es3Njr2THIo7qoDMQKn3M=" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="completed keyexchange" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=debug msg="completed challenge" Jun 01 15:05:34 volumio go-librespot[1642]: time="2025-06-01T15:05:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:36 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:36 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Jun 01 15:05:37 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:37 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:37 volumio go-librespot[1650]: go-librespot daemon starting... Jun 01 15:05:37 volumio go-librespot[1650]: time="2025-06-01T15:05:37Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:37 volumio go-librespot[1650]: time="2025-06-01T15:05:37Z" level=debug msg="app state loaded" Jun 01 15:05:37 volumio go-librespot[1650]: time="2025-06-01T15:05:37Z" level=debug msg="stored credentials not found" Jun 01 15:05:37 volumio go-librespot[1650]: time="2025-06-01T15:05:37Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=info msg="zeroconf server listening on port 37807" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="obtained new client token: AAAxsGV3iEEcEyHqdBdyWMKf36r/iQA5DOdlY9C9QXbL5F3YS2u85Tjh2ScCwBB/oQracxFCNkVo1JgPK52bOVKLlFQpSC3iAbM/pQw6PvaPnQNeO73EaoGyZAtPJ5hNHroLTlKIilP9cxEk1zvkNM/THwiLhz9m4CYC68adJ2G5I2db6V0B3K1NJQsXrAKySQLjmNetJSewtjhUxDz2qRufYlP/GJY48vpIK1SuJAzO3l7yXuyi19w=" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="completed keyexchange" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=debug msg="completed challenge" Jun 01 15:05:38 volumio go-librespot[1650]: time="2025-06-01T15:05:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:39 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:39 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Jun 01 15:05:41 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:41 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:41 volumio go-librespot[1658]: go-librespot daemon starting... Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=debug msg="app state loaded" Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=debug msg="stored credentials not found" Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:41 volumio go-librespot[1658]: time="2025-06-01T15:05:41Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:42 volumio go-librespot[1658]: time="2025-06-01T15:05:42Z" level=info msg="zeroconf server listening on port 46227" Jun 01 15:05:42 volumio go-librespot[1658]: time="2025-06-01T15:05:42Z" level=debug msg="obtained new client token: AACF0BJy+EExYm/mZ1AE7q2vdzYnbM3ljxM7Pa6tP2YR0Ux5andWxwONmpjpg3Bc0UP+wcMHFWJHwwfU8Eh0rUKMZQwxJWNKTf1Z0uOeQ+rWVcpkyeKc+JnTJhPDncbpQcIVZvrJcj18SG1ur7iLNwf5AqZKyC95tbUz+uE7+7XXA3OgqE6uZlkKsO2dcjExcHT/B4OOvrIX/m4RKHcBrnWcPzldYc0IfL+vozrlWgYf7W7GRWZH" Jun 01 15:05:42 volumio go-librespot[1658]: time="2025-06-01T15:05:42Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:42 volumio go-librespot[1658]: time="2025-06-01T15:05:42Z" level=debug msg="completed keyexchange" Jun 01 15:05:42 volumio go-librespot[1658]: time="2025-06-01T15:05:42Z" level=debug msg="completed challenge" Jun 01 15:05:42 volumio go-librespot[1658]: time="2025-06-01T15:05:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:42 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:42 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 01 15:05:43 volumio volumio[813]: info: Getting Alsa Cards List without I2S DAC Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 01 15:05:43 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 01 15:05:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Jun 01 15:05:45 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:45 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:45 volumio go-librespot[1674]: go-librespot daemon starting... Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="app state loaded" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="stored credentials not found" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=info msg="zeroconf server listening on port 46415" Jun 01 15:05:45 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="new websocket client" Jun 01 15:05:45 volumio volumio[813]: info: Connection to go-librespot Websocket established Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="obtained new client token: AABbdRIbopqOrto8FeYtJX3Ua+mrBDM4WP5+yFwouqtsQNP52S8X7qRpKex/w3JLSb8waBHyZn692+7xHGi2g/fTnovpsCkAsojhES4JQLeljc2i3+7bbWlEo3Wz8cSVY1dUOBLFI4Q4B5qIwYrHVnMbVwL0zemnixPkJ/XF+uHifqhbEWDT6dhu4RhfHjTHCZ4Y/+o72cVNF3dOJ+VQFr84/0D/rNb+sZcsTvKdfDk8ml4p4zcjh5k=" Jun 01 15:05:45 volumio go-librespot[1674]: time="2025-06-01T15:05:45Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:46 volumio go-librespot[1674]: time="2025-06-01T15:05:46Z" level=debug msg="completed keyexchange" Jun 01 15:05:46 volumio go-librespot[1674]: time="2025-06-01T15:05:46Z" level=debug msg="completed challenge" Jun 01 15:05:46 volumio go-librespot[1674]: time="2025-06-01T15:05:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:46 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jun 01 15:05:48 volumio volumio[813]: info: Getting Spotify volume Jun 01 15:05:48 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:48 volumio volumio[813]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 01 15:05:48 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 11) Jun 01 15:05:48 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Jun 01 15:05:48 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:05:48 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:05:49 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:49 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Jun 01 15:05:49 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:49 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:49 volumio go-librespot[1682]: go-librespot daemon starting... Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="app state loaded" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="stored credentials not found" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=info msg="zeroconf server listening on port 38937" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="obtained new client token: AABhSOZKJqTfDpaLn/KEyXZNkqOAsvBiZqgvdLLYJ4BA+e0vDmY4QptLkrRVmKRrDUZ9ds0uq/RzTjknWcOwwzpeGLBFFLL1UnowVrOlGK0WHAzN3AZ9tQnzYby8Z46baf7sJ3jm/YlHbewjMt4f+6TIsMVR+9rbtO7RuGReCPRDj8+r1EZtRrFkuMr7zZZvifWTdRoGalHMtkReouryAMoEbRxlIfVfiLN33ug2oniwhXL7nzeSgT4=" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="completed keyexchange" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=debug msg="completed challenge" Jun 01 15:05:49 volumio go-librespot[1682]: time="2025-06-01T15:05:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:50 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 15:05:50 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 01 15:05:52 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:52 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Jun 01 15:05:53 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:53 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:53 volumio go-librespot[1691]: go-librespot daemon starting... Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="app state loaded" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="stored credentials not found" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=info msg="zeroconf server listening on port 41269" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="obtained new client token: AACLfEQfEhSMyTXTDaAVHmudgMVz8vBfJMHAO4whRGvPDaoY2r8JcWyWmA+u5nbi32fBPi0nmhk/raFcYv+72LiJz89QP6ihwhJOIgqOP/TmB1nWSlhiBe5/U9J6PqW8A1NbsSqVrMsTJU5cpShWouYVFJULnheOOET9e6Rf2mIgAw/GG4jyFhNxlE7kWTVaDv0oP8kFEKB0b6mq2W2G8BFDCS4lsUuS27LUARJxJSVOgUoqlxAJagk=" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="completed keyexchange" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=debug msg="completed challenge" Jun 01 15:05:53 volumio go-librespot[1691]: time="2025-06-01T15:05:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:55 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:55 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:05:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:05:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Jun 01 15:05:56 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:05:56 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:05:56 volumio go-librespot[1700]: go-librespot daemon starting... Jun 01 15:05:56 volumio go-librespot[1700]: time="2025-06-01T15:05:56Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:05:56 volumio go-librespot[1700]: time="2025-06-01T15:05:56Z" level=debug msg="app state loaded" Jun 01 15:05:56 volumio go-librespot[1700]: time="2025-06-01T15:05:56Z" level=debug msg="stored credentials not found" Jun 01 15:05:56 volumio go-librespot[1700]: time="2025-06-01T15:05:56Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=info msg="zeroconf server listening on port 41631" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="obtained new client token: AAC3oaAgljAQrmGauIVawzNxHreWp+jd4fQtCLJle9I87GLkjwZKJKlCydiZoCb4tAWiT4WqEW41XCY86NDOyhDu0dRQh8fgrr5hDFm2bETsmbtNtPzIstkr6WN141hi+v8rLUNbaE+FpTB7JEvW5gO1TTqvvptLRlFBN6hTG59HD2rZxrLFE/51bgkqkRDd2dlXxdXd0HTLbe2AlDA0zkz8idWKn1mS/7W9icbTx1RGNP/Aw6Fyd58=" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="completed keyexchange" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=debug msg="completed challenge" Jun 01 15:05:57 volumio go-librespot[1700]: time="2025-06-01T15:05:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:05:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:05:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:05:58 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:05:58 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:00 volumio volumio[813]: info: CoreCommandRouter::volumioGetQueue Jun 01 15:06:00 volumio volumio[813]: info: CoreStateMachine::getQueue Jun 01 15:06:00 volumio volumio[813]: info: CorePlayQueue::getQueue Jun 01 15:06:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Jun 01 15:06:00 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:00 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:00 volumio go-librespot[1708]: go-librespot daemon starting... Jun 01 15:06:00 volumio go-librespot[1708]: time="2025-06-01T15:06:00Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:00 volumio go-librespot[1708]: time="2025-06-01T15:06:00Z" level=debug msg="app state loaded" Jun 01 15:06:00 volumio go-librespot[1708]: time="2025-06-01T15:06:00Z" level=debug msg="stored credentials not found" Jun 01 15:06:00 volumio go-librespot[1708]: time="2025-06-01T15:06:00Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=info msg="zeroconf server listening on port 36181" Jun 01 15:06:01 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="new websocket client" Jun 01 15:06:01 volumio volumio[813]: info: Connection to go-librespot Websocket established Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="obtained new client token: AADlXEgLeE+HAhsiTGStFVdXdxGMMZQFyY41vkV+lUiqEmdQDEfUrtNMz+ARWJ0pdDRCJD7b/3ksyN7iKuO8ldI2vmyS/E5y8KTet+8fXKsNHQgDsOdrVKdTdtQU0eS6oQ6g9j0e0DAh0JSCD7o4BcWfZ99ESHLLptv8PL4ZcugoO9qgLb1vzNTImhJHCymvbIj6EQn7CeWpVFbS0uyJOusCfCmf6/0UInzKD29oZsvwf6tMhtiv" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="completed keyexchange" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=debug msg="completed challenge" Jun 01 15:06:01 volumio go-librespot[1708]: time="2025-06-01T15:06:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:01 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jun 01 15:06:04 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:06:04 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:06:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Jun 01 15:06:04 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:04 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:04 volumio go-librespot[1716]: go-librespot daemon starting... Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="app state loaded" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="stored credentials not found" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:04 volumio volumio[813]: info: Getting Spotify volume Jun 01 15:06:04 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="new websocket client" Jun 01 15:06:04 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Jun 01 15:06:04 volumio volumio[813]: info: Connection to go-librespot Websocket established Jun 01 15:06:04 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:06:04 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=info msg="zeroconf server listening on port 46193" Jun 01 15:06:04 volumio go-librespot[1716]: time="2025-06-01T15:06:04Z" level=debug msg="obtained new client token: AAByG6+RknPFuAARWtNeZw20pepCATawxH8zpWwZWLd8taZ+N8JCZ0XQoqPjAx8LIGGGwhVCQhj8sE0ttKAJfppsUAtzDLIAUbxz/T9LnQIqxTEKbfkmzyEB8Plt+W80qFot0oqLXgXcXK6Eg5FGluuMm/7QsqzEEOXkWSne1u3QQPGSG69BlC3A9GYzNwufIpmmpvqU85Jtay8bB+OKl59jIZvok29tjda3M3KAAU1M/NwUCoi8Nr0=" Jun 01 15:06:05 volumio go-librespot[1716]: time="2025-06-01T15:06:05Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:05 volumio go-librespot[1716]: time="2025-06-01T15:06:05Z" level=debug msg="completed keyexchange" Jun 01 15:06:05 volumio go-librespot[1716]: time="2025-06-01T15:06:05Z" level=debug msg="completed challenge" Jun 01 15:06:05 volumio go-librespot[1716]: time="2025-06-01T15:06:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:05 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 01 15:06:05 volumio volumio[813]: at connResetException (internal/errors.js:607:14) Jun 01 15:06:05 volumio volumio[813]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 01 15:06:05 volumio volumio[813]: at Socket.emit (events.js:327:22) Jun 01 15:06:05 volumio volumio[813]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 01 15:06:05 volumio volumio[813]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 01 15:06:05 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 12) Jun 01 15:06:05 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jun 01 15:06:07 volumio volumio[813]: info: Getting Spotify volume Jun 01 15:06:07 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:07 volumio volumio[813]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 01 15:06:07 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 13) Jun 01 15:06:07 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Jun 01 15:06:07 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:06:07 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:06:08 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:08 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:08 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 01 15:06:08 volumio volumio[813]: info: In handleBrowseUri, curUri=spotify Jun 01 15:06:08 volumio volumio[813]: info: Preload queue cleared Jun 01 15:06:08 volumio volumio[813]: info: Preload queue cleared Jun 01 15:06:08 volumio volumio[813]: info: Preload queue cleared Jun 01 15:06:08 volumio volumio[813]: info: Preload queue cleared Jun 01 15:06:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Jun 01 15:06:08 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:08 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:08 volumio go-librespot[1724]: go-librespot daemon starting... Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=debug msg="app state loaded" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=debug msg="stored credentials not found" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:08 volumio go-librespot[1724]: time="2025-06-01T15:06:08Z" level=info msg="zeroconf server listening on port 35289" Jun 01 15:06:09 volumio go-librespot[1724]: time="2025-06-01T15:06:09Z" level=debug msg="obtained new client token: AACT38ZO/1X4TDPepEG7UdEj3lMJM0EGg6G0LKuHQ9bHm6UyPxMAnCoW19ZA7p1fd45JzkS1LvnKNvJnrSNRA6B9JtlJ+mLTdvSN2Q2xPx5lPwu7VWSlUVNEm4hPhTEbAf5m79V12csLDi9TR4fbSNLvoN02KEK0ltlvau8t3pzykM7zK00zBtOTBMmvzona+QMG3yPLE1mG8OcGOgarxMMfjOnwA9rKvCAK4La8ojR8z+C8Xnap" Jun 01 15:06:09 volumio go-librespot[1724]: time="2025-06-01T15:06:09Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:09 volumio go-librespot[1724]: time="2025-06-01T15:06:09Z" level=debug msg="completed keyexchange" Jun 01 15:06:09 volumio go-librespot[1724]: time="2025-06-01T15:06:09Z" level=debug msg="completed challenge" Jun 01 15:06:09 volumio go-librespot[1724]: time="2025-06-01T15:06:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:10 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 01 15:06:10 volumio volumio[813]: info: In handleBrowseUri, curUri=spotify/playlists Jun 01 15:06:10 volumio volumio[813]: info: Preload queue cleared Jun 01 15:06:11 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:11 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Jun 01 15:06:12 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:12 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:12 volumio go-librespot[1732]: go-librespot daemon starting... Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="app state loaded" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="stored credentials not found" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=info msg="zeroconf server listening on port 42737" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="obtained new client token: AABXUSltiqCxnc9y9/HFNSF2ICHpBCSif0Y0QPCTAxiRhZf8HJP8r0uQSzNG8k8QezO5xaurhtylN+P5FaImq9VBXOpmNasaYjbCgHlg6J1EJnBVlob+8cAIup8VTtv1xPEELNNAXcwjrt3H34TaSmoRXQ4Kq0tpO3zNrplFCyvFF4IAdIwRPCfvjZ2bq/X4kZ74O3z/HGOWJlj+TxiPKFHwYWXPKAQkaLn1LGpvQXoSke0YE9yM7UE=" Jun 01 15:06:12 volumio go-librespot[1732]: time="2025-06-01T15:06:12Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:13 volumio go-librespot[1732]: time="2025-06-01T15:06:13Z" level=debug msg="completed keyexchange" Jun 01 15:06:13 volumio go-librespot[1732]: time="2025-06-01T15:06:13Z" level=debug msg="completed challenge" Jun 01 15:06:13 volumio go-librespot[1732]: time="2025-06-01T15:06:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:14 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:14 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Jun 01 15:06:16 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:16 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:16 volumio go-librespot[1741]: go-librespot daemon starting... Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="app state loaded" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="stored credentials not found" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=info msg="zeroconf server listening on port 39337" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="obtained new client token: AAA8C+8Zg2A3FUpz04UTXnUlzL4YITJNsgl/1PXSOQ92xtvx3vDyniczAHqts+ruhT0yF9zuntnm41z7r75BxsO5daXSMRQ4fqP0VDnaboVvnkDl8oru6rkw0KvOnKFJD5HFSgU5PwDOYrh1Nd/+yIB6n/AWvvHw5jbatQXbBFAbZnPmM4/72CRoCmrqCnBI0nrsTaS3hKPFKKgjlutFuQ6UNM1nq9zm+kyT2PiDJGvV53jEeg2t+50=" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="completed keyexchange" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=debug msg="completed challenge" Jun 01 15:06:16 volumio go-librespot[1741]: time="2025-06-01T15:06:16Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:17 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:17 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Jun 01 15:06:19 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:19 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:19 volumio go-librespot[1749]: go-librespot daemon starting... Jun 01 15:06:19 volumio go-librespot[1749]: time="2025-06-01T15:06:19Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:19 volumio go-librespot[1749]: time="2025-06-01T15:06:19Z" level=debug msg="app state loaded" Jun 01 15:06:19 volumio go-librespot[1749]: time="2025-06-01T15:06:19Z" level=debug msg="stored credentials not found" Jun 01 15:06:19 volumio go-librespot[1749]: time="2025-06-01T15:06:19Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:20 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="new websocket client" Jun 01 15:06:20 volumio volumio[813]: info: Connection to go-librespot Websocket established Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=info msg="zeroconf server listening on port 36777" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="obtained new client token: AABUDeQN+RGoHN7qoeUi/lU7dRJOcKwNZPKWuZM3DAEhbG5010fJT1tpXvN9wP8HgOOiXWmthz/W2jktzjGMkfVNFrzIARl6w+iwBu/a1KAW+a4M28iPUIE5SDHrxBwo4XEY4QyHkBFsCdg2EA104sLRvTZv5Lo/vTIxSOyi8XVCERRaV8LneFdyVoMhJfeziTZHfHejQG+Zl/IzsCVgmMIkCvnmcK9tBYZaf1dVQmACC7TIqZX5zwQ=" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="completed keyexchange" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=debug msg="completed challenge" Jun 01 15:06:20 volumio go-librespot[1749]: time="2025-06-01T15:06:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:20 volumio volumio[813]: info: Connection to go-librespot Websocket closed Jun 01 15:06:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:23 volumio volumio[813]: info: Getting Spotify volume Jun 01 15:06:23 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:23 volumio volumio[813]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 01 15:06:23 volumio volumio[813]: (node:813) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 14) Jun 01 15:06:23 volumio volumio[813]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Jun 01 15:06:23 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:06:23 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:06:23 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:23 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Jun 01 15:06:23 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:23 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:23 volumio go-librespot[1757]: go-librespot daemon starting... Jun 01 15:06:23 volumio go-librespot[1757]: time="2025-06-01T15:06:23Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:23 volumio go-librespot[1757]: time="2025-06-01T15:06:23Z" level=debug msg="app state loaded" Jun 01 15:06:23 volumio go-librespot[1757]: time="2025-06-01T15:06:23Z" level=debug msg="stored credentials not found" Jun 01 15:06:23 volumio go-librespot[1757]: time="2025-06-01T15:06:23Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=info msg="zeroconf server listening on port 35767" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="obtained new client token: AADlArNpbyN2HTMwtOMGMMpE2CFdBwF8MseSznKz+Jbxjp3fTVBPLi90mFYkNazjScY2guFvcueof5RE4eN9AxrjfAC642iAivpvIR1GMoy5yDOkEjQjSAjl/nxbcsv7ZY3gjIne72HFx4nfvrcOjm+noVHdBHAQmJdWJjAAeyoPrcNLf675kyh6Ger/i0//NRD0tJSHpeIcveUE7GT+/K8IzZWL3+o2IADzqEPqh23qNduRCAw+" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="completed keyexchange" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=debug msg="completed challenge" Jun 01 15:06:24 volumio go-librespot[1757]: time="2025-06-01T15:06:24Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:26 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:26 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Jun 01 15:06:27 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:27 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:27 volumio go-librespot[1765]: go-librespot daemon starting... Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="app state loaded" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="stored credentials not found" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=info msg="zeroconf server listening on port 45847" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="obtained new client token: AAAjt1wTQimbMP3dW7XiWy3jtw/+OcU+5k7wFbJYr1rQJas2HL3Wk/M0Jf5ZH89Ksl7B5GM+DdiXA70giGzsUQYoKOwBgt4IHIj7g+60oTERc7XVEeJ8vTQFTX6NXHE7TZrepytzmEaPiUlbzSytZs4RvM2A8g1mbZSdBn/pG2VNeg1fs1q4NrGIoqGGPVAMc2Qi8FDDh8wYMkj/a8maLETJhx3zFbU55yLSsqLKfFcjf0w4llG1om0=" Jun 01 15:06:27 volumio go-librespot[1765]: time="2025-06-01T15:06:27Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:28 volumio go-librespot[1765]: time="2025-06-01T15:06:28Z" level=debug msg="completed keyexchange" Jun 01 15:06:28 volumio go-librespot[1765]: time="2025-06-01T15:06:28Z" level=debug msg="completed challenge" Jun 01 15:06:28 volumio go-librespot[1765]: time="2025-06-01T15:06:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:29 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:29 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Jun 01 15:06:31 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:31 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:31 volumio go-librespot[1774]: go-librespot daemon starting... Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="app state loaded" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="stored credentials not found" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=info msg="zeroconf server listening on port 35797" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="obtained new client token: AACUL2wl5eca3Jjded4d53gcryrSxiC89NvCKZUF59dEErZR+BLKujeoIYHXtjdy3lLjbfma8oU/LiNBa9KD4gLkNiN25DW074izOkXf9BSWRdyAdXCihBXmiOMESd93b3Uvs4qpiQIhh73cG4BAikJVAry9p7+20NFeqwDrnNNIfNvPUo3HiGcbcY2E+vI4cA1tnkfNnbRQuKD5pYW66BU36RhIy092cu8vDrTyRaiWk2PF3bL+xxc=" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="completed keyexchange" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=debug msg="completed challenge" Jun 01 15:06:31 volumio go-librespot[1774]: time="2025-06-01T15:06:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:32 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:32 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:34 volumio volumio[813]: info: CoreCommandRouter::volumioGetState Jun 01 15:06:34 volumio volumio[813]: info: CorePlayQueue::getTrack 0 Jun 01 15:06:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Jun 01 15:06:34 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:34 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:34 volumio go-librespot[1783]: go-librespot daemon starting... Jun 01 15:06:34 volumio go-librespot[1783]: time="2025-06-01T15:06:34Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:34 volumio go-librespot[1783]: time="2025-06-01T15:06:34Z" level=debug msg="app state loaded" Jun 01 15:06:34 volumio go-librespot[1783]: time="2025-06-01T15:06:34Z" level=debug msg="stored credentials not found" Jun 01 15:06:34 volumio go-librespot[1783]: time="2025-06-01T15:06:34Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=info msg="zeroconf server listening on port 42659" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="obtained new client token: AAAnUKkV2WGXMbc+q8+C9D2aWCydBIW4MLYQzYQkSYINNTX+t0UH0BrSB6LsLY4JCjWt2LH+/K02fMlNkzUV7kwyfRa6JS4TDNcu5e3Qh9L6vznepxyLl3qJfkvDmmloc/w/QaPMSGSersfWF6qjA9a3irA5iSnupW+Chvax+aJS5xk4m8HXUGuRqakQUhEnHGO6L+9DGO1BqsKfn4wi9DLQPlgtCD7q6Kwgaj3KBRMRABLbI187n3Q=" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="completed keyexchange" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=debug msg="completed challenge" Jun 01 15:06:35 volumio go-librespot[1783]: time="2025-06-01T15:06:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:35 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:35 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Jun 01 15:06:38 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:38 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:38 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:38 volumio go-librespot[1792]: go-librespot daemon starting... Jun 01 15:06:38 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:38 volumio go-librespot[1792]: time="2025-06-01T15:06:38Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:38 volumio go-librespot[1792]: time="2025-06-01T15:06:38Z" level=debug msg="app state loaded" Jun 01 15:06:38 volumio go-librespot[1792]: time="2025-06-01T15:06:38Z" level=debug msg="stored credentials not found" Jun 01 15:06:38 volumio go-librespot[1792]: time="2025-06-01T15:06:38Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=info msg="zeroconf server listening on port 40405" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="obtained new client token: AACYOxM/EfU7BoCnIv/YCQ3ecMvMM6pvFWFWHPskYXoNjCGkE5XoiMfkXfPfKZP6t9BlJx5EEv2ZvRCQp2t3A7FRHVw0BXJk7phjpUpy73BA1skYKd+nIZiXzS8Sa/xFIG6pIQXObhy5+ldrrLseVTc75FjW+sO/XStJFlo4UUTfFelXYv50d8XXPEWW/aJPR2rLoDi4GmS3N+Bli5+Ja2O0wB5uzzwE1NEm0t8y7FThBIfYqxcz" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="completed keyexchange" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=debug msg="completed challenge" Jun 01 15:06:39 volumio go-librespot[1792]: time="2025-06-01T15:06:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:41 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:41 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 15:06:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Jun 01 15:06:42 volumio systemd[1]: Stopped go-librespot Daemon. Jun 01 15:06:42 volumio systemd[1]: Started go-librespot Daemon. Jun 01 15:06:42 volumio go-librespot[1800]: go-librespot daemon starting... Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=info msg="running go-librespot 0.2.0" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="app state loaded" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="stored credentials not found" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=info msg="zeroconf server listening on port 46605" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="obtained new client token: AABK2HdX2SM7TtqySEHxYhBMqX0hAiUMn8ellOy56CQgXJbdygmMvQqR7KWOm80TLApAyENAE0fsrEW1VksNhJvNJVzwlKDg3GfB4/JkdOEFtOSwO6QCKxcZQMUCNX7/2No7TVYBiUfi1NxzL8O9AtzW4oWDiQrAxEeDjr5u85kUZ0Q8ZxLT2yA4k0BrJhhF3exYtKm55fvmGcLRDPn+HgUwSkjH1h+MkjizP3NMZTxdes0rAzhw8vk=" Jun 01 15:06:42 volumio go-librespot[1800]: time="2025-06-01T15:06:42Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 15:06:43 volumio go-librespot[1800]: time="2025-06-01T15:06:43Z" level=debug msg="completed keyexchange" Jun 01 15:06:43 volumio go-librespot[1800]: time="2025-06-01T15:06:43Z" level=debug msg="completed challenge" Jun 01 15:06:43 volumio go-librespot[1800]: time="2025-06-01T15:06:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 01 15:06:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 15:06:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 15:06:44 volumio volumio[813]: info: Initializing connection to go-librespot Websocket Jun 01 15:06:44 volumio volumio[813]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 15:06:44 volumio volumio[813]: info: CoreCommandRouter::executeOnPlugin: metavolumio , superSearch Jun 01 15:06:44 volumio volumio[813]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 15:06:44 volumio volumio[813]: TypeError: Cannot read property 'then' of undefined Jun 01 15:06:44 volumio volumio[813]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:470:20) Jun 01 15:06:44 volumio volumio[813]: at Socket.emit (events.js:315:20) Jun 01 15:06:44 volumio volumio[813]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Jun 01 15:06:44 volumio volumio[813]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jun 01 15:06:44 volumio volumio[813]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 15:06:45 volumio sudo[1818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-01 15:05 Jun 01 15:06:45 volumio sudo[1818]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"