-- Logs begin at Wed 2024-10-09 18:23:54 CEST, end at Thu 2024-10-10 19:16:52 CEST. -- Oct 10 19:15:06 volumio ntpd[781]: receive: Unexpected origin timestamp 0xeab12ceb.75c15abf does not match aorg 0000000000.00000000 from server@5.250.191.170 xmt 0xeab28a1a.27ccb1aa Oct 10 19:15:06 volumio ntpd[781]: receive: Unexpected origin timestamp 0xeab12ceb.75b96711 does not match aorg 0000000000.00000000 from server@178.215.228.24 xmt 0xeab28a1a.2a80f850 Oct 10 19:15:06 volumio ntpd[781]: receive: Unexpected origin timestamp 0xeab12ceb.75b3cb47 does not match aorg 0000000000.00000000 from server@89.140.186.3 xmt 0xeab28a1a.2959f67d Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: A device disappeared from network Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: Device volumio disappeared from network Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: A device disappeared from network Oct 10 19:15:06 volumio systemd[1]: Starting Daily apt download activities... Oct 10 19:15:06 volumio volumio[1072]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: adding efc9ccaa-1330-483a-93d2-f85d68dbe24c Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: Found device Volumio Oct 10 19:15:06 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:15:06 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:15:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Oct 10 19:15:06 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: this is already registered, efc9ccaa-1330-483a-93d2-f85d68dbe24c Oct 10 19:15:06 volumio volumio[1072]: info: Discovery: Found device Volumio Oct 10 19:15:06 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:15:06 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:15:06 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:06 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:06 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:06 volumio go-librespot[1809]: Librespot-go daemon starting... Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=info msg="generated new device id: 37e15b2e3428dbb5765e65b9580aff845e1aa6fe" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="zeroconf server listening on port 42269" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="obtained new client token: AACMJIUe5SucNSj3czhMn4e9NfArgbKE8Ju58HPRaulRKxNLV7f20SZIS8iT9AYgSicWQ2vNCc1ipWQrS0/iIoFak21og2vu5CQiJQh+kA037/ZTd0L0+PnDW6tqQxUGuwor3M9beLxZND/V5qdVAlPsqHxvZNG1vo1gq0WQ7baP0AOjwOaVMNNV1arI1rF/OKB/qZRniUzpUwevZQn6c1LuymUkeeB59rhqnYi1Ty3v3RZGYX3fOv+e" Oct 10 19:15:06 volumio go-librespot[1809]: time="2024-10-10T19:15:06+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:07 volumio go-librespot[1809]: time="2024-10-10T19:15:07+02:00" level=debug msg="completed challenge" Oct 10 19:15:07 volumio go-librespot[1809]: time="2024-10-10T19:15:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:08 volumio systemd[1]: apt-daily.service: Succeeded. Oct 10 19:15:08 volumio systemd[1]: Started Daily apt download activities. Oct 10 19:15:08 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Oct 10 19:15:08 volumio volumio[1072]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 19:15:09 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:09 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:09 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Oct 10 19:15:09 volumio systemd[1]: Started Daily apt upgrade and clean activities. Oct 10 19:15:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Oct 10 19:15:10 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:10 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:10 volumio go-librespot[1916]: Librespot-go daemon starting... Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=info msg="generated new device id: 4e8647901eed2df54499f49901a4411cd77dc408" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="zeroconf server listening on port 39097" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="obtained new client token: AAA6FzC/DoiVg4BZACl47cLLEMrWlDFw2Vxi3kncSI1MygNyz4A2nmGmE7kRdPSnJfGp+bNw1rpzob7LFv+sqGcUZaTodGsmwrgr6oNbVUGheUUcXlLm9gjosZOEucOtr+evLY+EK59wn/fNANU07WG0eM7x/WIUE6wUXQUzNuCpYU1QCBGh/hEqmKh2J1OtmUTfyVFELpLboGRCHpVR6jWc2T7HH/JSe7em3W1oUL0ZuOEs3SNvA2w9" Oct 10 19:15:10 volumio go-librespot[1916]: time="2024-10-10T19:15:10+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:11 volumio go-librespot[1916]: time="2024-10-10T19:15:11+02:00" level=debug msg="completed challenge" Oct 10 19:15:11 volumio go-librespot[1916]: time="2024-10-10T19:15:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:11 volumio volumiossh-tunnel[1571]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Oct 10 19:15:12 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:12 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Oct 10 19:15:14 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:14 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:14 volumio go-librespot[1924]: Librespot-go daemon starting... Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=info msg="generated new device id: 6a954a34f15f48d3cd36549b3ed7a18cb629c81f" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="zeroconf server listening on port 41891" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="obtained new client token: AABvK2b1z5l3x4bttbH9dbChWcj0SjUmrgj9RNZ6Hrun+kUHFIv4A0K6CTzntiHWAuiMHlkO6odXNOy3wNrJWHxqLBTarWt5possQtPP0wvBZyERh7FUOv/hlZda6rADFFycmk96fOkQniu1HvbQWn9cloKxfjcJRX6l5HICCLT5/3tY+VoQAXVM3XmoMAeaVEVpdDsHXf+Z8UM7DCXY6gJd4cqzbJl8TgA2IY/+cZ5gpZENpibuI+WK" Oct 10 19:15:14 volumio go-librespot[1924]: time="2024-10-10T19:15:14+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:15 volumio go-librespot[1924]: time="2024-10-10T19:15:15+02:00" level=debug msg="completed challenge" Oct 10 19:15:15 volumio go-librespot[1924]: time="2024-10-10T19:15:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:15 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:15 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Oct 10 19:15:18 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:18 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:18 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:18 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:18 volumio go-librespot[1932]: Librespot-go daemon starting... Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=info msg="generated new device id: 86e1ea21ca7cdf6a49cbba23a8589e1cdb64c247" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="zeroconf server listening on port 45435" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="obtained new client token: AAAYijzivW5hOrIyiFG0H8w+ONL55yOcLHBGkfJdLgknCwGZzLa8FKMmeDoUIAtl50oYG66AbTqGKSVLWf9h5tLBxAv75nRDirVsRCCZQcRIT6c1ZMjEG3WQRkJInQTOyJKjHVgjAyZwFprnZehyPNfMV4AyT7vMjHoMs1Y1vCJDtyDFykcW+8QbcvDTrX8akBi6N1RC2Mp5Lq+NelidI7fZ/7Q7LvJrTSj1sNiMM6sTRhdWLeceVMkr" Oct 10 19:15:18 volumio go-librespot[1932]: time="2024-10-10T19:15:18+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:19 volumio go-librespot[1932]: time="2024-10-10T19:15:19+02:00" level=debug msg="completed challenge" Oct 10 19:15:19 volumio go-librespot[1932]: time="2024-10-10T19:15:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:21 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:21 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Oct 10 19:15:22 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:22 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:22 volumio go-librespot[1940]: Librespot-go daemon starting... Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=info msg="generated new device id: 5ed075d0b0474877012f979097eda8a014976fe5" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="zeroconf server listening on port 33517" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="obtained new client token: AADxcdBVnaJRuC3YZKmoQdmO4bAAZWOO8pvWhWPh1XNrcIJXSQK7uaxuYNrbHDTv2MbDKu3y7LH7lLsXf1RZaGr4TvLqB5ThFwtYCTc3zCmv4xEazosICLvtNHsdLlusNKH0iBeI48MYy5Huz520qO/TyaiAWuyT0aJ5s53A9UY2c0SDN2d0REujfutZWHpCqfpcFk2Ykro4wGVive4EdjNuw4nJIDpNLMlGjsnkWjj9mFbyrc3aT9kQ" Oct 10 19:15:22 volumio go-librespot[1940]: time="2024-10-10T19:15:22+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:23 volumio go-librespot[1940]: time="2024-10-10T19:15:23+02:00" level=debug msg="completed challenge" Oct 10 19:15:23 volumio go-librespot[1940]: time="2024-10-10T19:15:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:24 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:24 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Oct 10 19:15:26 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:26 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:26 volumio go-librespot[1948]: Librespot-go daemon starting... Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=info msg="generated new device id: 851dafb65c32441adb51fcd043d979b5a600361c" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="zeroconf server listening on port 45459" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="obtained new client token: AABKTyneLR0E2fIubN13tBHhoSCnRcHLe5q5cQQWWzZ3G0ullCntHodOqpJKnhaPy/jKaREqeU4PMT1eMkXP/QE3G0K4O9bzOTMiapiPg7AXOGFY6hakfcSmTVroEAnlBzfSz8IRfTBFIW0IJj5UqrY8/5rej7nsL62IuiCZPCnzw9Xv3nsy8f2aZNTe7fwEYP/kmGOczx3uJJ8ICaSkBTH77UqW6657lwdyutPtXv0pSXS3UGQOYtAE" Oct 10 19:15:26 volumio go-librespot[1948]: time="2024-10-10T19:15:26+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:27 volumio go-librespot[1948]: time="2024-10-10T19:15:27+02:00" level=debug msg="completed challenge" Oct 10 19:15:27 volumio go-librespot[1948]: time="2024-10-10T19:15:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:27 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:27 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Oct 10 19:15:30 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:30 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:30 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:30 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:30 volumio go-librespot[1957]: Librespot-go daemon starting... Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=info msg="generated new device id: d010ae02d91e0b5aeb45270b065bd49a60591b84" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="zeroconf server listening on port 37599" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="obtained new client token: AAAc/GFT3HFLpbd8xU9zhlkXFL87l3CzQlM3o9kvOJefixv0iPi/1QmXhnVEw6iwipyjSaf6MMRUJFmvHP0cWJyfkUOJ9YZ9eQZPR6VDLR9dq0RdFNAtpvCghHxWXGp5jBoa4JhGhBcrqrxGWNEVpW0cOMkCWnrrYJoSlNcu9Dnrp3K76D60qjH6Kgsa4oWu1lGJrYffK6BBcsU5CItR5tnOJQOFwwtk8vcTijR1THEetTWFROriPWWC" Oct 10 19:15:30 volumio go-librespot[1957]: time="2024-10-10T19:15:30+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:31 volumio go-librespot[1957]: time="2024-10-10T19:15:31+02:00" level=debug msg="completed challenge" Oct 10 19:15:31 volumio go-librespot[1957]: time="2024-10-10T19:15:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:33 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:33 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Oct 10 19:15:34 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:34 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:34 volumio go-librespot[1965]: Librespot-go daemon starting... Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=info msg="generated new device id: 0fef45a480b373313ad434dfe58d779c1da5b295" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="zeroconf server listening on port 38041" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="obtained new client token: AACAYo239OLKaN23nvboaD+Ab8xloo6Z5XCdqBziG1RWyalivP8ghcrgQFgSJNrVXOf8pJMYWMQJHUJZ9gNECiYEgKFFbXPzRZzZ9XiYg3qdDaq3HUFqPanSwwIVsKIElR3mVH0wIrBXeIKgwaGVPP/5ZlPgqChCtmY/XyMKSXVB74k8SpiYs13pnMM++Y7JsBj9B8og83lrI/rm3u+uQJ2BxwLTSTcef6DKNtvunb9USiT8nTQVwePK" Oct 10 19:15:34 volumio go-librespot[1965]: time="2024-10-10T19:15:34+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:35 volumio go-librespot[1965]: time="2024-10-10T19:15:35+02:00" level=debug msg="completed challenge" Oct 10 19:15:35 volumio go-librespot[1965]: time="2024-10-10T19:15:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:36 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:36 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Oct 10 19:15:38 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:38 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:38 volumio go-librespot[1973]: Librespot-go daemon starting... Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=info msg="generated new device id: 607a64a9447239d4e7f3d64ce888317101be4b5d" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="zeroconf server listening on port 35565" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="obtained new client token: AABr3/Bsizya/SAVqu5ARQndvwew9w5BkWFa8rK7CP/FVnZnadNJzvDEGrLBdlUqOpVztBCuzh9poSa4/VlhpG9eQ+JnUnKZfJlwmyy7T8JkKN14AqaIShmVmfm2VKra53esQp5RctoPeo9GPnYdwd0DX5Zlu0WWze8UBFTswfHzGeWaJfIsWSiS/2IHxhzzhKJDTvxehuAkNu6QpJr/y3u9Q9BOsXbODJoCnuwQo//CUbAetHudK3dR" Oct 10 19:15:38 volumio go-librespot[1973]: time="2024-10-10T19:15:38+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:39 volumio go-librespot[1973]: time="2024-10-10T19:15:39+02:00" level=debug msg="completed challenge" Oct 10 19:15:39 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:39 volumio go-librespot[1973]: time="2024-10-10T19:15:39+02:00" level=debug msg="new websocket client" Oct 10 19:15:39 volumio volumio[1072]: info: Connection to go-librespot Websocket established Oct 10 19:15:39 volumio go-librespot[1973]: time="2024-10-10T19:15:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:39 volumio volumio[1072]: info: Connection to go-librespot Websocket closed Oct 10 19:15:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:42 volumio volumio[1072]: info: Getting Spotify volume Oct 10 19:15:42 volumio volumio[1072]: (node:1072) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:42 volumio volumio[1072]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 10 19:15:42 volumio volumio[1072]: (node:1072) 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: 3) Oct 10 19:15:42 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 10 19:15:42 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:15:42 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:15:42 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Oct 10 19:15:42 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:42 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Oct 10 19:15:42 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:42 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:42 volumio go-librespot[1981]: Librespot-go daemon starting... Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=info msg="generated new device id: 3b53f04947c9a74bd06a91fcacbecc3b94c9bbf0" Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=debug msg="zeroconf server listening on port 38819" Oct 10 19:15:42 volumio go-librespot[1981]: time="2024-10-10T19:15:42+02:00" level=debug msg="obtained new client token: AADOK7+PzG3ky9PIYMVNI6L0PloKwT9UvzAA6Fj3YflL5JsuTjuxWttaQeTVnsIs5CFJW7B1zDQtVwy/U98sLcKwvvbdSYaUPPtkTt54TniSwQmvSzs+nLO+JTDAEmgInxhOGRIAGVphl+zYAf856u2s0aS+nKog+YaqctfiZPvH5q/tnu671yPmPTeyM66PQZpn4aGjzNfGU80wsfk5lc1w/81zpBv914SyMLLb7g1L8ehHqhdjRmH7" Oct 10 19:15:43 volumio go-librespot[1981]: time="2024-10-10T19:15:43+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:43 volumio go-librespot[1981]: time="2024-10-10T19:15:43+02:00" level=debug msg="completed challenge" Oct 10 19:15:43 volumio go-librespot[1981]: time="2024-10-10T19:15:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:45 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:45 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Oct 10 19:15:46 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:46 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:46 volumio go-librespot[1990]: Librespot-go daemon starting... Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=info msg="generated new device id: e716a565d2f083ebb3ebae16be38188f60ee4757" Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=debug msg="zeroconf server listening on port 44327" Oct 10 19:15:46 volumio go-librespot[1990]: time="2024-10-10T19:15:46+02:00" level=debug msg="obtained new client token: AAC3W6ff1V1xjLGvNDebKpC456nj0y4+X/McrQd2DmD7WMIXk0ftNIwyE/V0Lc627ERTPxLBNy8kh7/C9DO8cmcziwKMjRpMUC4Q8o3E1E22aIaW8JRhgagsjmB4wXmEdpE9o6PaE7qURd//wmtr97RiuG1fGCphtxsC7XTG8itvEeoFb7jWmRSdDg1qJRGldP8uM8PILDrp+v/pBtEI4IAlQP0W+IPGCfx5Ie9W8AMtZ43pnmze8iOw" Oct 10 19:15:47 volumio go-librespot[1990]: time="2024-10-10T19:15:47+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:47 volumio go-librespot[1990]: time="2024-10-10T19:15:47+02:00" level=debug msg="completed challenge" Oct 10 19:15:47 volumio go-librespot[1990]: time="2024-10-10T19:15:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:48 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:48 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Oct 10 19:15:50 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:50 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:50 volumio go-librespot[2036]: Librespot-go daemon starting... Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=info msg="generated new device id: 90ae5da96cf76de8336d68f3412c90bcae71652d" Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=debug msg="zeroconf server listening on port 34701" Oct 10 19:15:50 volumio go-librespot[2036]: time="2024-10-10T19:15:50+02:00" level=debug msg="obtained new client token: AAD27ALLrz4rPHX/y/5+EzUsKUFpNtO25iq+aLQcSZ7TCsUgcuZ7D46u/BMVowQCEos5/AB3oVPM7HAE6rKEsGxo6fdYj2wtPWHClP3yVnV0m1nZXs0UR1Q4rMLifn1ZwuII/BUKLxdalsP66+tIyQOS8erHQZewiSwtkM+RfglcnyNRD6ODK9J/XccLCSvcsO9hCY83dZcHW8n7c7iXcIcGZwwbOz3ERHIv4xnem4LBqD8zbyScGj0L" Oct 10 19:15:51 volumio go-librespot[2036]: time="2024-10-10T19:15:51+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:51 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:51 volumio go-librespot[2036]: time="2024-10-10T19:15:51+02:00" level=debug msg="new websocket client" Oct 10 19:15:51 volumio volumio[1072]: info: Connection to go-librespot Websocket established Oct 10 19:15:51 volumio go-librespot[2036]: time="2024-10-10T19:15:51+02:00" level=debug msg="completed challenge" Oct 10 19:15:51 volumio go-librespot[2036]: time="2024-10-10T19:15:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:51 volumio volumio[1072]: info: Connection to go-librespot Websocket closed Oct 10 19:15:54 volumio volumio[1072]: info: Getting Spotify volume Oct 10 19:15:54 volumio volumio[1072]: (node:1072) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:54 volumio volumio[1072]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 10 19:15:54 volumio volumio[1072]: (node:1072) 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: 4) Oct 10 19:15:54 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 10 19:15:54 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:15:54 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:15:54 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Oct 10 19:15:54 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:54 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Oct 10 19:15:54 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:54 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:54 volumio go-librespot[2044]: Librespot-go daemon starting... Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=info msg="generated new device id: 6a89e7d0bb242bfafc28e13213306416221545ab" Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=debug msg="zeroconf server listening on port 42877" Oct 10 19:15:54 volumio go-librespot[2044]: time="2024-10-10T19:15:54+02:00" level=debug msg="obtained new client token: AACtc6e7+WAsfrIQcr1EFBjPt7b9WA6+6Zxx0m46pRjUJ3FOuzuLYczonO+Tlw1lQsyYRhPBxvtZ5tr3Nf6YojwvX6wrO+Xk638QxpB8rHwzl8LkGO6nop9nntP9CzMj7XbltUZajbUsze7bc9+F4ZaFDEPbbj2I4qyVqokTvYS7SUejGzXkGvFo8diBtLOVlyfwtsADbGC8vdgEnkrSp4FcUymxXhUyKVSz7f8/kiC+JisHLl+smKfj" Oct 10 19:15:55 volumio go-librespot[2044]: time="2024-10-10T19:15:55+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:55 volumio go-librespot[2044]: time="2024-10-10T19:15:55+02:00" level=debug msg="completed challenge" Oct 10 19:15:55 volumio go-librespot[2044]: time="2024-10-10T19:15:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:15:57 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:15:57 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:15:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:15:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Oct 10 19:15:58 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:15:58 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:15:58 volumio go-librespot[2052]: Librespot-go daemon starting... Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=info msg="generated new device id: 4e36de0f077c684ecb704dd9653bd9fca079189d" Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=debug msg="stored credentials not found" Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=debug msg="zeroconf server listening on port 33561" Oct 10 19:15:58 volumio go-librespot[2052]: time="2024-10-10T19:15:58+02:00" level=debug msg="obtained new client token: AADsDx/oPq7jADkLDu0IWYVeNVxrV6gVmnqC3XtD6cw3mv2MspUXbSsl6wrxWxWcszL5vP5WvZV61sFjaRw70ws0cC6Is03gZ5Ofpga+NT4Oxxc68rHm4qkiSUSjE6WiT9WXZgkIZx7S2wTFZYoe7XtgM3sK5tZc3Vg6jr/EEPltlzL5J+9asMs6T+fGV+vOnejwejHuNP5lIIE5/NxsGphEe+ZmygvledgPW3TdZYEvNswKcRjzXqe4" Oct 10 19:15:59 volumio go-librespot[2052]: time="2024-10-10T19:15:59+02:00" level=debug msg="completed keyexchange" Oct 10 19:15:59 volumio go-librespot[2052]: time="2024-10-10T19:15:59+02:00" level=debug msg="completed challenge" Oct 10 19:15:59 volumio go-librespot[2052]: time="2024-10-10T19:15:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:15:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:15:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:00 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:00 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Oct 10 19:16:02 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:02 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:02 volumio go-librespot[2060]: Librespot-go daemon starting... Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=info msg="generated new device id: ff635d84477cb2fe5be2ac6add24908986f33bcb" Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=debug msg="zeroconf server listening on port 37973" Oct 10 19:16:02 volumio go-librespot[2060]: time="2024-10-10T19:16:02+02:00" level=debug msg="obtained new client token: AADNSuUyv5GbKffLT8qIcPuueGCdoMaBQwzz5BdfaFfe2AZPA40pQXbhWfTovO4Sb9NuhZr4V066Cll6yyhlpu4Lc7f+mkQdImv18hJ8HHpPwyfDGprU4LoR/DGJdF15u+FfByDmHojw0qYGjaqxSGRDD6WvpKIhYXZxTm0vYF7fA5biknMTC1LeTbTECuev9RMcbyNN5SBqUaNqdjoxQv4UKzFgcNpbsKYJ5IVqRLXNPm/VmhWn10qp" Oct 10 19:16:03 volumio go-librespot[2060]: time="2024-10-10T19:16:03+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:03 volumio go-librespot[2060]: time="2024-10-10T19:16:03+02:00" level=debug msg="completed challenge" Oct 10 19:16:03 volumio go-librespot[2060]: time="2024-10-10T19:16:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:03 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:03 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:06 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:06 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Oct 10 19:16:06 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:06 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:06 volumio go-librespot[2069]: Librespot-go daemon starting... Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=info msg="generated new device id: 33ba79a29f886a0ae752a883e6c7ade6d71ac9ac" Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=debug msg="zeroconf server listening on port 33757" Oct 10 19:16:06 volumio go-librespot[2069]: time="2024-10-10T19:16:06+02:00" level=debug msg="obtained new client token: AADm+SkxjluUD2Vv7tahd2ws5awgSuhasCxjoJlMOr1NZXL5w7P23NHCAwiX59BZLYXcBmnV7K00lHH0wpBLuILk3C/Rlxagi10UA5zYnu9uAUGfIWVZ6d75EsNCPEqeI5eYO1pEmsBlM2PpMiWTJvpXjXOFUK58Jpb3CSHbY9bw+Dm+B0bSX0srl3hUVLNVo/2J11P7TprkHRPccPGaS47AqN5qkrNYj0CU6vYPMDHgYnaZMty0SmGS" Oct 10 19:16:07 volumio go-librespot[2069]: time="2024-10-10T19:16:07+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:07 volumio go-librespot[2069]: time="2024-10-10T19:16:07+02:00" level=debug msg="completed challenge" Oct 10 19:16:09 volumio go-librespot[2069]: time="2024-10-10T19:16:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:09 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:09 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Oct 10 19:16:12 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:12 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:12 volumio go-librespot[2077]: Librespot-go daemon starting... Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=info msg="generated new device id: f60e9975e1fef70da32362761c873895c326c884" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="zeroconf server listening on port 33013" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="obtained new client token: AABFWmQz6foIOrNn8Wog9W/uZvuC0xu06YEntcKg1RXVHMT9GNuUYZomNkWlbLpuWWiou743KblAlXA7lx0EhpyhdT5HuFdJnnOKMEpEOwAfvr+IOs/9tKIkA8kSN/1R+i0eFsAV0hFiF03B3EuFmQJh5td92P8aDmQ9HKFkhmV8TWTA4kMkvB2vjnC6FdHkk8v4Jtkxswgo+mG/BBoGkfW7/AEcLVG92XjRslawuSLRnqnTJPpW6VXt" Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:12 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:12 volumio go-librespot[2077]: time="2024-10-10T19:16:12+02:00" level=debug msg="new websocket client" Oct 10 19:16:12 volumio volumio[1072]: info: Connection to go-librespot Websocket established Oct 10 19:16:13 volumio go-librespot[2077]: time="2024-10-10T19:16:13+02:00" level=debug msg="completed challenge" Oct 10 19:16:13 volumio go-librespot[2077]: time="2024-10-10T19:16:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:13 volumio volumio[1072]: info: Connection to go-librespot Websocket closed Oct 10 19:16:15 volumio volumio[1072]: info: Getting Spotify volume Oct 10 19:16:15 volumio volumio[1072]: (node:1072) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:15 volumio volumio[1072]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 10 19:16:15 volumio volumio[1072]: (node:1072) 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: 5) Oct 10 19:16:15 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 10 19:16:15 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:16:15 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:16:15 volumio volumio[1072]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Oct 10 19:16:16 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:16 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Oct 10 19:16:16 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:16 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:16 volumio go-librespot[2085]: Librespot-go daemon starting... Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=info msg="generated new device id: c2082a2b70d909c520364ba88635228005d9aeae" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="zeroconf server listening on port 34915" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="obtained new client token: AABm57NVfqdQskkmffCY7cyKY3LIXRAg/sSP0d7d1SXe8uaeyIn3dH5+9ntS924xkGQHT0yGZL2NNL2xGcmYMEdoDAcFei8KFSRZnvz/GizIJebSQrI488+PB9Ox9lBzFvXk5J5630Pb8tQmjYrMOGgyfm13BCu/zTvoKrG6KqriQEg2ZRaluGfAD+0sy4+wEXadpGB1CuqbO2CTTWRS9hiFT6Oz9Io/+kppuOFYwWtaaU337DybBXzP" Oct 10 19:16:16 volumio go-librespot[2085]: time="2024-10-10T19:16:16+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:17 volumio go-librespot[2085]: time="2024-10-10T19:16:17+02:00" level=debug msg="completed challenge" Oct 10 19:16:17 volumio go-librespot[2085]: time="2024-10-10T19:16:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:19 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:19 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Oct 10 19:16:20 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:20 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:20 volumio go-librespot[2093]: Librespot-go daemon starting... Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=info msg="generated new device id: d0a685fe3bdf0964e35176621399152d589baa7d" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="zeroconf server listening on port 44861" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="obtained new client token: AAB086H9BIkgHrpTsfdY0gdn9p8xCHEw291iyCBTwbHldRmVw1W9IErZnxxs02WvVIDAwoCIB6fZmcZmjUbYdh40RG5ImyErWYf6PmR/0tnHbhy95Vg2VaTQVs7H4nimFWEYBhHip1vwurXxsBx0FfUTDsId6nDXRaDw9os9vrqOz48LvIyJvK9wP16rM3IE7spG2om+Gcixee51YG8I0jhl/JGWQmNsnUghZvgXu579kE4ibJiGHi18" Oct 10 19:16:20 volumio go-librespot[2093]: time="2024-10-10T19:16:20+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:21 volumio go-librespot[2093]: time="2024-10-10T19:16:21+02:00" level=debug msg="completed challenge" Oct 10 19:16:21 volumio go-librespot[2093]: time="2024-10-10T19:16:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:22 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:22 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Oct 10 19:16:24 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:24 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:24 volumio go-librespot[2101]: Librespot-go daemon starting... Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=info msg="generated new device id: 25de8f93746e2235926bd078b75bb2344472ce0d" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="zeroconf server listening on port 46269" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="obtained new client token: AAA2XvcLGMwj9wPc1T6iqTLXG+OtzUr/36KdZ63GQmmkYIJ8uvnxjjdLeK5JS/+PVAk3NBk3nQ4V8U9mTpwH/hwKKNZlaGz+w/8sV1eP9KlgCexeezpJWUR/zQJeFGrWNXJ331GleRxfJUllJ8HxSjzDhax/bR3kgV1nz+SYwDSpPQoHNrRt24J9TJNSKgh61KIec/74cbH3ph3PnramHbtUiD51G3uqqBZGoDW0R7jwZ1MNsAxygc2l" Oct 10 19:16:24 volumio go-librespot[2101]: time="2024-10-10T19:16:24+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:25 volumio go-librespot[2101]: time="2024-10-10T19:16:25+02:00" level=debug msg="completed challenge" Oct 10 19:16:25 volumio go-librespot[2101]: time="2024-10-10T19:16:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:25 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:25 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:27 volumio volumio[1072]: verbose: New Socket.io Connection to 192.168.1.36 from 192.168.1.33 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.0 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 8 Oct 10 19:16:27 volumio volumio[1072]: info: CoreCommandRouter::volumioGetVisibleSources Oct 10 19:16:27 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 10 19:16:27 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:16:27 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:16:27 volumio volumio[1072]: info: CoreCommandRouter::volumioGetQueue Oct 10 19:16:27 volumio volumio[1072]: info: CoreStateMachine::getQueue Oct 10 19:16:27 volumio volumio[1072]: info: CorePlayQueue::getQueue Oct 10 19:16:27 volumio volumio[1072]: info: Listing playlists Oct 10 19:16:27 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 10 19:16:27 volumio volumio[1072]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 10 19:16:28 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:28 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Oct 10 19:16:28 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:28 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:28 volumio go-librespot[2110]: Librespot-go daemon starting... Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=info msg="generated new device id: 691417ca7864c6edefb051a4f6ffaf3bd83325d7" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="zeroconf server listening on port 39819" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="obtained new client token: AACTGhVy8s4cYn8MVrc3oBPrEF46rnBnClYs6YjlVN04vTOq9b0qr7uSyzuqYUq/uy35D5vBqWukV4HJW1OCfypH+YVN1oIwLIwWHlKW1en51CP3jprHVapqHK5a1NZi4Q3u1PSxStpBbpKDUU8T+9dkSYoHQjbwfYuEe8B/D1h4+6bpjNvfpRstTlE/XOva2UKCz1VZ6zO+f1MaePKs4bIuzFRIQCiqs4A+BeZReIKCU7hjy00dwiKr" Oct 10 19:16:28 volumio go-librespot[2110]: time="2024-10-10T19:16:28+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:29 volumio go-librespot[2110]: time="2024-10-10T19:16:29+02:00" level=debug msg="completed challenge" Oct 10 19:16:29 volumio go-librespot[2110]: time="2024-10-10T19:16:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:29 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 10 19:16:29 volumio volumio[1072]: info: Received Get System Info Oct 10 19:16:29 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 10 19:16:29 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 10 19:16:29 volumio volumio[1072]: info: Discovery: Getting this device information Oct 10 19:16:29 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:16:29 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:16:29 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 10 19:16:31 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:31 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Oct 10 19:16:32 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:32 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:32 volumio go-librespot[2118]: Librespot-go daemon starting... Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=info msg="generated new device id: 60017a3d120712ea0a36dd8b0c06d642301667bd" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="zeroconf server listening on port 38991" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="obtained new client token: AADm66BAmERyHDOG47FORnG3ZmfcPysK2w3/V0o9j/jeYqwKpOzehgZw4+Ygtv+yC376rj5zi13O5pJGV6Dr6VvuqfekTAIWCEGbk7Z3cxJbLtSJxSgfr01X19E3YO8Rq2GHWPPPw+KYvybzOJf0h0OdG/9eiQeSTvg12+LxBH7LiTo5MJI3TTA4v6EAs2HEwMDi5C8PRSNyuvWeECGL9ss8jXUm67TDBhiAaTRPZtCLl98MbD/mNMU+" Oct 10 19:16:32 volumio go-librespot[2118]: time="2024-10-10T19:16:32+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:33 volumio go-librespot[2118]: time="2024-10-10T19:16:33+02:00" level=debug msg="completed challenge" Oct 10 19:16:33 volumio go-librespot[2118]: time="2024-10-10T19:16:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:33 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 10 19:16:33 volumio volumio[1072]: info: Preload queue cleared Oct 10 19:16:34 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:34 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:35 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 10 19:16:35 volumio volumio[1072]: info: Preload queue cleared Oct 10 19:16:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Oct 10 19:16:36 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:36 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:36 volumio go-librespot[2127]: Librespot-go daemon starting... Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=info msg="generated new device id: 878db932debc42a19774666f5be36b13338aba12" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="zeroconf server listening on port 46473" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="obtained new client token: AAA2aBzSP/yJhBRxx5mcRhQmUR9b+fhL4wdnxTOzyguvBhQm3+fnv65AZ0z5xmuqibY8wGmAkyGhoN85YxyIFEZY48APFzhi/Np765kPHFepLm+Pyy7Msg63fk0SBlwDcuyFfqQfFSH8pw3RuC/+BKU9/6PYc5ZU2dg1eC3QXdg+xXHupjyuyCxgo/uLFUiULq1OW8sflaXgajzbuv686fAYgAC2z3TL+M383i8hj9DOglAq/L/VmZ/p" Oct 10 19:16:36 volumio go-librespot[2127]: time="2024-10-10T19:16:36+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:37 volumio go-librespot[2127]: time="2024-10-10T19:16:37+02:00" level=debug msg="completed challenge" Oct 10 19:16:37 volumio go-librespot[2127]: time="2024-10-10T19:16:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:37 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:37 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:40 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:40 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Oct 10 19:16:40 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:40 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:40 volumio go-librespot[2135]: Librespot-go daemon starting... Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=info msg="generated new device id: 2bbeb8e71a2b2feb10019c487e27149436da5fb1" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="zeroconf server listening on port 40543" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="obtained new client token: AABNx9QOpYh/8knwm9vRnSduYksekUE7WrAu4jbK+vWWkfDLihyVt0J87ecLBa2hHjRak1Jh8EorxSv566XJKF/ClF/QtbKJrMqh7dMb+JSAZtLpaoltxnoZclyILiI2hAf19JaF9AgX3PXlQrBiM8mEuN6kZnO68f4UdQNmRZmJbQjAHePNHsnIaxZ9UImNBj690D2irOyGL0xu0Rb5ll9cQ3cMizTGl2euoxvfrm/r/Iac5IuWRZqq" Oct 10 19:16:40 volumio go-librespot[2135]: time="2024-10-10T19:16:40+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:41 volumio go-librespot[2135]: time="2024-10-10T19:16:41+02:00" level=debug msg="completed challenge" Oct 10 19:16:41 volumio go-librespot[2135]: time="2024-10-10T19:16:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:41 volumio volumio[1072]: info: Tunnel connection is inactive, restarting it Oct 10 19:16:41 volumio volumio[1072]: info: Starting Tunnel 1 Oct 10 19:16:41 volumio volumio[1072]: info: Starting Tunnel Connection Checker Oct 10 19:16:41 volumio sudo[2149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 10 19:16:41 volumio sudo[2149]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 19:16:41 volumio autossh[1572]: received signal to exit (15) Oct 10 19:16:41 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Oct 10 19:16:41 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Oct 10 19:16:41 volumio systemd[1]: sshtunnel.service: Succeeded. Oct 10 19:16:41 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Oct 10 19:16:41 volumio volumio[1072]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 10 19:16:41 volumio volumio[1072]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 10 19:16:41 volumio systemd[1]: Started MyVolumio SSH Tunnel. Oct 10 19:16:41 volumio sudo[2149]: pam_unix(sudo:session): session closed for user root Oct 10 19:16:41 volumio volumio[1072]: info: Remote SSH Started Oct 10 19:16:41 volumio autossh[2152]: port set to 0, monitoring disabled Oct 10 19:16:41 volumio autossh[2152]: starting ssh (count 1) Oct 10 19:16:41 volumio autossh[2152]: ssh child pid is 2155 Oct 10 19:16:41 volumio volumio[1072]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 10 19:16:41 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState Oct 10 19:16:41 volumio volumio[1072]: info: CorePlayQueue::getTrack 0 Oct 10 19:16:43 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:43 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Oct 10 19:16:44 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:44 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:44 volumio go-librespot[2156]: Librespot-go daemon starting... Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=info msg="generated new device id: 791d02ed185a1234903b0095eeb9df43b62c65a2" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="zeroconf server listening on port 38319" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="obtained new client token: AADebrUY+t8povH7S5qVWxyktPipsmyovzM/bmj79pvp3LdOMDTFhFCdLYWz3OrFnbJ6q0AJXdmzG1BUMNDky4G8wUiwmFv++S8rjCtZlmLLUHU+gT4Id8abI/7IxDRSrP5fzVdn0mY3vv7ZQP2r2eIZpFAd2pdn77zsg8BeH/3AcGKhF1gik3B/uOir34ZsNwzsvX+iwtqOM+OpWyINkOCDBeiWSelwVVwc4tISTiSQw6i2sMqN3CdM" Oct 10 19:16:44 volumio go-librespot[2156]: time="2024-10-10T19:16:44+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:45 volumio go-librespot[2156]: time="2024-10-10T19:16:45+02:00" level=debug msg="completed challenge" Oct 10 19:16:45 volumio go-librespot[2156]: time="2024-10-10T19:16:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:46 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:46 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:47 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 10 19:16:47 volumio volumio[1072]: info: Preload queue cleared Oct 10 19:16:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Oct 10 19:16:48 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:48 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:48 volumio go-librespot[2165]: Librespot-go daemon starting... Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=info msg="generated new device id: fa05fa3062044f771b16133ec348b0c44c50b42c" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="zeroconf server listening on port 37321" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="obtained new client token: AAAU+YQfCXbzptPvEEL/WlqSzM3UCJxOZLEOJKW43aVAvNAm0dVadNaaYpNOJ/BXnmtcEGK2eZGy6+kyovztE5f+h+esvm7IdgshMZ1j4jYoQ4nvQzAprCXHCX6vfxYzF8UTgyfJwk8hJyve2LRRMhUmp9/7ZafRwKb46YLBckKEoxWbfpM4CyzNrHddK32vlp6YKXAhaIjMTRMcvewXaDqBdR/LX1cKoLgrEjhR1lg8JwYLcHhm6Y8w" Oct 10 19:16:48 volumio go-librespot[2165]: time="2024-10-10T19:16:48+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:49 volumio go-librespot[2165]: time="2024-10-10T19:16:49+02:00" level=debug msg="completed challenge" Oct 10 19:16:49 volumio go-librespot[2165]: time="2024-10-10T19:16:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 10 19:16:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 10 19:16:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 10 19:16:49 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:49 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:51 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 10 19:16:51 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 10 19:16:52 volumio volumio[1072]: info: Initializing connection to go-librespot Websocket Oct 10 19:16:52 volumio volumio[1072]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 10 19:16:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 10 19:16:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Oct 10 19:16:52 volumio systemd[1]: Stopped go-librespot Daemon. Oct 10 19:16:52 volumio systemd[1]: Started go-librespot Daemon. Oct 10 19:16:52 volumio go-librespot[2211]: Librespot-go daemon starting... Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=info msg="generated new device id: dbbf2cb69aa0b009e118b164f3538bce4e66e72b" Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="stored credentials not found" Oct 10 19:16:52 volumio volumio[1072]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 19:16:52 volumio volumio[1072]: TypeError: Cannot read property 'length' of undefined Oct 10 19:16:52 volumio volumio[1072]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 10 19:16:52 volumio volumio[1072]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 10 19:16:52 volumio volumio[1072]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 10 19:16:52 volumio volumio[1072]: at Parser.emit (events.js:315:20) Oct 10 19:16:52 volumio volumio[1072]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 10 19:16:52 volumio volumio[1072]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 10 19:16:52 volumio volumio[1072]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 10 19:16:52 volumio volumio[1072]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 10 19:16:52 volumio volumio[1072]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 10 19:16:52 volumio volumio[1072]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 10 19:16:52 volumio volumio[1072]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 10 19:16:52 volumio volumio[1072]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 10 19:16:52 volumio volumio[1072]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 10 19:16:52 volumio volumio[1072]: at IncomingMessage.emit (events.js:327:22) Oct 10 19:16:52 volumio volumio[1072]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 10 19:16:52 volumio volumio[1072]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 10 19:16:52 volumio volumio[1072]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="zeroconf server listening on port 34051" Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="obtained new client token: AAC/o1ylqC4NQXuMcChmuQDuDIFT0snhiOxjja5TLFRjpM+MEJrf/BabqMvFr16pAKD6JNpC5CZIgJYtVJiJZWNSNEEvEHqdSBacB2giqsPr9SbOE6odlzVyQFU/v8a/p3MrG2A9hvJiG4qQ/jdT9oFtjOV8CAvKDaEJV7VsVc/Oc9wGbdpocJw+WT8Wcph7o5KQD6np3Z+nKW2+6CAORWa2oTIR18dI0T5prT97iURXbU3SSLkSiRBg" Oct 10 19:16:52 volumio go-librespot[2211]: time="2024-10-10T19:16:52+02:00" level=debug msg="completed keyexchange" Oct 10 19:16:52 volumio sudo[2228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-10 19:15 Oct 10 19:16:52 volumio sudo[2228]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"