-- Logs begin at Mon 2025-05-19 08:51:47 EDT, end at Mon 2025-05-19 08:56:43 EDT. -- May 19 08:55:01 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:01 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:01 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:01 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. May 19 08:55:01 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:01 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:01 volumio-office go-librespot[2500]: go-librespot daemon starting... May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=debug msg="app state loaded" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=debug msg="stored credentials not found" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:01 volumio-office go-librespot[2500]: time="2025-05-19T08:55:01-04:00" level=info msg="zeroconf server listening on port 40909" May 19 08:55:02 volumio-office go-librespot[2500]: time="2025-05-19T08:55:02-04:00" level=debug msg="obtained new client token: AABzr16kuoV6DBGZfUO2K90HvbJm9wikXzVyjiUFkjQyVbGklH1Jbpqgg/DmAst5Cky6K9Tv37w8aKOCJn5FK3sSrOuj9E5wsZpYw9ontRPsS2a5bYDdd4ictHjMNv7+kNHG9Y+f7qzEjsEBg1xPNA/bUd9h/WA+y72jHhjz9M+sQ7ZAsskN01i2dYXJ8+juLu/M7bpHwSSTWiCukfX5Ov/oTWgPj8T7h6+V8/HB/vbFhKDQagM3u+g=" May 19 08:55:02 volumio-office go-librespot[2500]: time="2025-05-19T08:55:02-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:02 volumio-office go-librespot[2500]: time="2025-05-19T08:55:02-04:00" level=debug msg="completed keyexchange" May 19 08:55:02 volumio-office go-librespot[2500]: time="2025-05-19T08:55:02-04:00" level=debug msg="completed challenge" May 19 08:55:02 volumio-office go-librespot[2500]: time="2025-05-19T08:55:02-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:02 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:02 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:04 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:04 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:05 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:05 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. May 19 08:55:05 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:05 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:05 volumio-office go-librespot[2508]: go-librespot daemon starting... May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="app state loaded" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="stored credentials not found" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=info msg="zeroconf server listening on port 46563" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="obtained new client token: AACd7N5PVQy3HrTQPLn8pzIp6jEP4Pu71ZqSIl7qAXMWB1D2xNYJQAamgaqDmQ1ilTRtNV9/K949Y4WFpgJ+YfQQR8OjnOo12x7/R0LLg+LAQpCImRYL4rWnLHi/pCF8oT0fqRuR7sT5uMpCVmL5+msAB3TlcNH11IYaq8kpb54qfQqqiFGlk73Ck8Xt9j89gANtzxe8XIfUFMjkqgdbej7DKCMqQPbXZE0PKYmVYfAcr5esvIxgIH2B+g==" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="completed keyexchange" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=debug msg="completed challenge" May 19 08:55:05 volumio-office go-librespot[2508]: time="2025-05-19T08:55:05-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:05 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:05 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:07 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:07 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:08 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:08 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. May 19 08:55:08 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:08 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:08 volumio-office go-librespot[2541]: go-librespot daemon starting... May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=debug msg="app state loaded" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=debug msg="stored credentials not found" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:08 volumio-office go-librespot[2541]: time="2025-05-19T08:55:08-04:00" level=info msg="zeroconf server listening on port 41325" May 19 08:55:09 volumio-office go-librespot[2541]: time="2025-05-19T08:55:09-04:00" level=debug msg="obtained new client token: AADp2ir+lzbFPDDJYq43wN3y4c12VuoybqiGD3eQPHcxRYQ9qf6zvvjAy6K1uIhN7MsvPTqslyV/SvKHFWou/MTyNPYvhbmlxagP+u5Lb0UNfz68eJhl5jZ3OupoiwJQAYU9qZBL/ABWpjaFn2LogEwllPDLZx2UVuATfa8o0DHpuDzaYBM9lbLBFDvVQhFsdqp6S0kOS4EM4q892hVOlFWkZsw3k5hpdxRTMcD59T9u3TDEVYzjN9w=" May 19 08:55:09 volumio-office go-librespot[2541]: time="2025-05-19T08:55:09-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" May 19 08:55:09 volumio-office go-librespot[2541]: time="2025-05-19T08:55:09-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" May 19 08:55:09 volumio-office go-librespot[2541]: time="2025-05-19T08:55:09-04:00" level=debug msg="completed keyexchange" May 19 08:55:09 volumio-office go-librespot[2541]: time="2025-05-19T08:55:09-04:00" level=debug msg="completed challenge" May 19 08:55:09 volumio-office go-librespot[2541]: time="2025-05-19T08:55:09-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:09 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:09 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:09 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:09 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:10 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:10 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:12 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:12 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. May 19 08:55:12 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:12 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:12 volumio-office go-librespot[2553]: go-librespot daemon starting... May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="app state loaded" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="stored credentials not found" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=info msg="zeroconf server listening on port 45105" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="obtained new client token: AADmD6dCyIANSmXJnf5Bi4DOOtrdPNcnfhqn1BddlHjkCpGg6DFAvx05z4p/OM/+GK8ax6vWPOcSfwfKpK+b8ZxJd9pY14QVfgIqzrWL7zpDkbNdkZqESvtnm/exHksddCUYmD3vvj5PdBUhFGTS67FwbfdTFeLeB7yanVjlHoj8J90YqGJ6A186FGdPLFywRDdprZkltxHLbTVmp0YB0u+XmbW8hvtExcbm4JvQL5jBqZjhiTGufVwaJg==" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="completed keyexchange" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=debug msg="completed challenge" May 19 08:55:12 volumio-office go-librespot[2553]: time="2025-05-19T08:55:12-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:12 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:12 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:13 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:13 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:15 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:15 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. May 19 08:55:15 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:15 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:15 volumio-office go-librespot[2561]: go-librespot daemon starting... May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=debug msg="app state loaded" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=debug msg="stored credentials not found" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:15 volumio-office go-librespot[2561]: time="2025-05-19T08:55:15-04:00" level=info msg="zeroconf server listening on port 45321" May 19 08:55:16 volumio-office go-librespot[2561]: time="2025-05-19T08:55:16-04:00" level=debug msg="obtained new client token: AACXY86GdKJ3dju0MRBYYyJucZcwQKMQVNs39wCEpcLcp+li9ni+uMoviJ56wH9ggBW9jnjGqdmAh5OkAzSKgpDbq160/bY5uWArhaXw7++UmYnWMcJLsCbwggv7FbWDtJtFFZhh44G6mjzI3cgoMifOSAUFYRt7MQr7u6Vo80iD5DviJjqPsaQJWqqTBATKKn8NPZ3X2TudsCB+xfGOR/2tYN2B4K6MIPOQRPaEJ9dTFOd2FZ4cEQQ=" May 19 08:55:16 volumio-office go-librespot[2561]: time="2025-05-19T08:55:16-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:16 volumio-office go-librespot[2561]: time="2025-05-19T08:55:16-04:00" level=debug msg="completed keyexchange" May 19 08:55:16 volumio-office go-librespot[2561]: time="2025-05-19T08:55:16-04:00" level=debug msg="completed challenge" May 19 08:55:16 volumio-office go-librespot[2561]: time="2025-05-19T08:55:16-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:16 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:16 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:16 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:16 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:19 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:19 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:19 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:19 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. May 19 08:55:19 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:19 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:19 volumio-office go-librespot[2594]: go-librespot daemon starting... May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="app state loaded" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="stored credentials not found" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=info msg="zeroconf server listening on port 45941" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="obtained new client token: AAAAE7fpFzVkuLfSJ8PBEW3WMZsaZSJRgemUtw1q7Z9uqeAZ9IDLY4vjHLDXzvvDsdMSrUVb1tvSI1OewlhPGeW41eLhwGII9INhbUyc6JcLmCmgM9hk+sGXuVCQPbLG3E/uZb8JC2QWph5JGyp0LNmJhWtrnYTyX6OvplHWrIYmW54C8FqPenD8xHAyBfZ9vKybKCRSO0S/Y+UyLRTs2DtvWvUKZYJ014X/Mh5NNXR/N7TrppCEDBF0zQ==" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="completed keyexchange" May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=debug msg="completed challenge" May 19 08:55:19 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:19 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:19 volumio-office volumio[1171]: info: Listing playlists May 19 08:55:19 volumio-office volumio[1171]: info: Listing playlists May 19 08:55:19 volumio-office go-librespot[2594]: time="2025-05-19T08:55:19-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:19 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:19 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:22 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:22 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:22 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:22 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. May 19 08:55:22 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:22 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:22 volumio-office go-librespot[2602]: go-librespot daemon starting... May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=debug msg="app state loaded" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=debug msg="stored credentials not found" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 19 08:55:22 volumio-office go-librespot[2602]: time="2025-05-19T08:55:22-04:00" level=info msg="zeroconf server listening on port 41327" May 19 08:55:23 volumio-office go-librespot[2602]: time="2025-05-19T08:55:23-04:00" level=debug msg="obtained new client token: AAA/9civi0dS5YE1ruixGWhyTRsLA3X2yau2+jZxYm1GHdG+yJ3cC6miHWOaL3ESAVumeZ/wx/Qy/gHTg7yr2D6bX5enaPJiycqISQwCe9mV4rbqV10RE/K+tjUZLt9inO7pKHMwKIuZQ0KGYLSxq0betnrh9jaG3VAh/NxLqCag63Qor30tBbUjJcPVr/mvZylv58Bhm9uQvUQG8I/x2CW31Lda6twsaiE1HCZqQiwOujwOUkz+SZI=" May 19 08:55:23 volumio-office go-librespot[2602]: time="2025-05-19T08:55:23-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:23 volumio-office go-librespot[2602]: time="2025-05-19T08:55:23-04:00" level=debug msg="completed keyexchange" May 19 08:55:23 volumio-office go-librespot[2602]: time="2025-05-19T08:55:23-04:00" level=debug msg="completed challenge" May 19 08:55:23 volumio-office go-librespot[2602]: time="2025-05-19T08:55:23-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:23 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:23 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:25 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:25 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:26 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:26 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. May 19 08:55:26 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:26 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:26 volumio-office go-librespot[2613]: go-librespot daemon starting... May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="app state loaded" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="stored credentials not found" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=info msg="zeroconf server listening on port 43405" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="obtained new client token: AABmgN5kZIQPtZwdMjyLX2/MDdldqpO3GkfBKDabsQvgOb//krf6JSHFAXEh3PXZGHyKBGJzZKSOMyXBGXbvh3JK9uBmUogEh1xml1akmibPnG7xs0JPP1DZZFNQIgQavTG1k4S80jbERixXAFPZO21bvkrxtAm+hj8GSw4p8M1xy8s94OLk0tQf6WgUYiMh5T//ptWOclQl6zJyAAswKNOY7PSCbmbB1sYMZhd1zrbo7X2YwX6izoZimw==" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="completed keyexchange" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=debug msg="completed challenge" May 19 08:55:26 volumio-office go-librespot[2613]: time="2025-05-19T08:55:26-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:26 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:26 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:28 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:28 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:29 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:29 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:29 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:29 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. May 19 08:55:29 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:29 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:29 volumio-office go-librespot[2646]: go-librespot daemon starting... May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=debug msg="app state loaded" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=debug msg="stored credentials not found" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 19 08:55:29 volumio-office go-librespot[2646]: time="2025-05-19T08:55:29-04:00" level=info msg="zeroconf server listening on port 37273" May 19 08:55:30 volumio-office go-librespot[2646]: time="2025-05-19T08:55:30-04:00" level=debug msg="obtained new client token: AADgbI9DV6mChAnP8LePxqZ8a8sFg3PYKzQnE4fgDDvxta8EyozVtdz8n4rlsK4tVVQ5IyPtVIYwb1+2VtwR1xlR/R3z4CcEPWc+IB7ivLzrtruTR8y0T+hgi7pRd8rSczQ5pEB5pfgMSJMnmWTYo+BMMuXicKuB/yH1SY8m8mQFGPFP5Y1YRvNMSc1kQGy4KpK73xx/aWqaj5GKT/yErUT3yBKLaHSOMMpKkD3YOVAVndDtc9iiNWc=" May 19 08:55:30 volumio-office go-librespot[2646]: time="2025-05-19T08:55:30-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:30 volumio-office go-librespot[2646]: time="2025-05-19T08:55:30-04:00" level=debug msg="completed keyexchange" May 19 08:55:30 volumio-office go-librespot[2646]: time="2025-05-19T08:55:30-04:00" level=debug msg="completed challenge" May 19 08:55:30 volumio-office go-librespot[2646]: time="2025-05-19T08:55:30-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:30 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:30 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:31 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:31 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:33 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:33 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. May 19 08:55:33 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:33 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:33 volumio-office go-librespot[2658]: go-librespot daemon starting... May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="app state loaded" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="stored credentials not found" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=info msg="zeroconf server listening on port 41791" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="obtained new client token: AAAvJt6aIp56OM4Dhsf/AkhC+HjTh6hOxK8anuJwEnz2EZamjZDvLgqyHi5+S6kd3IkJdN0VyN9POmeWoilY84gLY2G9nnFdRa+YfvA86A0tK5sK5auyW34dRNwF6cSw7Fw1u8GvTuCqtBu8zCA2mr1fFDvXENfpIItMLjpx9QRaY1QjWT8w+/QFtcRgjhKd5iTa1hGfSPRng1z7IPZKw3R9qghvX3kA5PvavkKEI8QOxh4BswoxK3G7FQ==" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="completed keyexchange" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=debug msg="completed challenge" May 19 08:55:33 volumio-office go-librespot[2658]: time="2025-05-19T08:55:33-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:33 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:33 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:34 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:34 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:36 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:36 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. May 19 08:55:36 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:36 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:36 volumio-office go-librespot[2666]: go-librespot daemon starting... May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=debug msg="app state loaded" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=debug msg="stored credentials not found" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:36 volumio-office go-librespot[2666]: time="2025-05-19T08:55:36-04:00" level=info msg="zeroconf server listening on port 34735" May 19 08:55:37 volumio-office go-librespot[2666]: time="2025-05-19T08:55:37-04:00" level=debug msg="obtained new client token: AACBe1B/DxGkpEvbFvjwrClQuMdPychFDsrCeLBByeMdev9HfPaitmvKzMDX8YmsBwSZszuNr2gWr3uIEl5xZFbjHhNPyQmi9WwORnTgWeC55qts+hJmKdLaSIiJgRDJpM52bWcBY7Ccj3WncIh5kxI8qtY+0hP2J3Nq6C72McYZq4BY05cmdwdWMKJEW373eJzYLOdAFPNMbpSDezdhZFPbseOUZGi9C+cVDotBq03NtcR0+P8v3wg=" May 19 08:55:37 volumio-office go-librespot[2666]: time="2025-05-19T08:55:37-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:37 volumio-office go-librespot[2666]: time="2025-05-19T08:55:37-04:00" level=debug msg="completed keyexchange" May 19 08:55:37 volumio-office go-librespot[2666]: time="2025-05-19T08:55:37-04:00" level=debug msg="completed challenge" May 19 08:55:37 volumio-office go-librespot[2666]: time="2025-05-19T08:55:37-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:37 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:37 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:37 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:37 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:38 volumio-office volumio[1171]: info: Clearing queue after UPNP request May 19 08:55:38 volumio-office volumio[1171]: info: CoreStateMachine::ClearQueue May 19 08:55:38 volumio-office volumio[1171]: info: CoreStateMachine::stop May 19 08:55:38 volumio-office volumio[1171]: info: CoreStateMachine::setConsumeUpdateService undefined May 19 08:55:38 volumio-office volumio[1171]: info: CorePlayQueue::clearPlayQueue May 19 08:55:38 volumio-office volumio[1171]: info: CorePlayQueue::saveQueue May 19 08:55:38 volumio-office volumio[1171]: info: CoreCommandRouter::volumioPushState May 19 08:55:38 volumio-office volumio[1171]: info: CoreCommandRouter::volumioPushQueue May 19 08:55:38 volumio-office volumio[1171]: error: Upnp client error: Error: This socket has been ended by the other party May 19 08:55:38 volumio-office volumio[1171]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 May 19 08:55:39 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:39 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:39 volumio-office volumio[1171]: info: Listing playlists May 19 08:55:39 volumio-office volumio[1171]: info: Listing playlists May 19 08:55:40 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:40 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:40 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:40 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. May 19 08:55:40 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:40 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:40 volumio-office go-librespot[2699]: go-librespot daemon starting... May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="app state loaded" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="stored credentials not found" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=info msg="zeroconf server listening on port 45545" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="obtained new client token: AABH6GaAUNT/J4Q7IOMZRque8PyabNI5biSFN+Jdw6+9HHlXfkf5PI4lrGJLnzt+jeKbDr4mx7Ypdpg1jN31dOpPOePjU3qLxmOQ/10TX3nmlIKsqrZQmobyupSB7/vtwbn3xp7ZWdXoo8ZJcVmFddb1OXVmDdlwYSjO8W9XlBRaM6CNhrFoyX87nJzl+c2hYH8OCP4u/Z9sB5S3Lwi7f+ocl6/tnatAIHhQwOkXhJysDA7AzvMUMqFeSg==" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:40 volumio-office volumio[1171]: info: Starting UPNP Playback May 19 08:55:40 volumio-office volumio[1171]: info: Preparing playback through UPNP May 19 08:55:40 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:40 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:40 volumio-office volumio[1171]: info: CoreStateMachine::setConsumeUpdateService mpd May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="completed keyexchange" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=debug msg="completed challenge" May 19 08:55:40 volumio-office go-librespot[2699]: time="2025-05-19T08:55:40-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:40 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:40 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 3ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 2ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 0ms May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 0ms May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 0ms May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: May 19 08:55:41 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:41 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 0ms May 19 08:55:41 volumio-office volumio[1171]: info: ------------------------------ 1ms May 19 08:55:43 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:43 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:43 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:43 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. May 19 08:55:43 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:43 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:43 volumio-office go-librespot[2724]: go-librespot daemon starting... May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=debug msg="app state loaded" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=debug msg="stored credentials not found" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:43 volumio-office go-librespot[2724]: time="2025-05-19T08:55:43-04:00" level=info msg="zeroconf server listening on port 38417" May 19 08:55:44 volumio-office go-librespot[2724]: time="2025-05-19T08:55:44-04:00" level=debug msg="obtained new client token: AAAJGGegM7t268LrLqpQm078nXUEAqgblBdihaGWtLZWuAXs+aPW1JNCCCvZ14k3pRwCklc69D/9O3k7Szio7Khn180CuJKNS8q1A7C2L/wj2CoukV0VFGEJHjqxRmnDfNaRNj/lNuN3T761ZpSBnpwcSCfqvdI/DhrHnM0Q18tIJmkTuuq3OFCI3GvIclQIiLDIvYZX10FoWgCq10wNnvsU1HkeH8ciDuV4KF1g4oeg4igIzRbOQRc=" May 19 08:55:44 volumio-office go-librespot[2724]: time="2025-05-19T08:55:44-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:44 volumio-office go-librespot[2724]: time="2025-05-19T08:55:44-04:00" level=debug msg="completed keyexchange" May 19 08:55:44 volumio-office go-librespot[2724]: time="2025-05-19T08:55:44-04:00" level=debug msg="completed challenge" May 19 08:55:44 volumio-office go-librespot[2724]: time="2025-05-19T08:55:44-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:44 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:44 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces state update: player May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::getState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand status May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces state update: player May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::getState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand status May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces state update: player May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::getState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand status May 19 08:55:46 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:46 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand status took 466 milliseconds May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:46 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces state update: player May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::getState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand status May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand status took 471 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand status took 470 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand playlistinfo took 4 milliseconds May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseTrackInfo May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::servicePushState May 19 08:55:46 volumio-office volumio[1171]: verbose: In UPNP mode May 19 08:55:46 volumio-office volumio[1171]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"246 Kbps","isStreaming":false,"title":"7e953fca50d94125ae5704a94525ced5.flac","artist":"Music Assistant","album":null,"uri":"http://192.168.3.181:8097/flow/N2GbHKAX/uuid:3f61d9e8-130c-7166-4b56-2ccf67020293/7e953fca50d94125ae5704a94525ced5.flac","trackType":"flac"} May 19 08:55:46 volumio-office volumio[1171]: verbose: CURRENT POSITION 0 May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState stateService play May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState currentStatus stop May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 476ms May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:46 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces state update: player May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::getState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand status May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces system playlist update May 19 08:55:46 volumio-office volumio[1171]: info: Ignoring MPD Status Update May 19 08:55:46 volumio-office volumio[1171]: info: May 19 08:55:46 volumio-office volumio[1171]: ---------------------------- MPD announces state update: player May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::getState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand status May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 6ms May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand status took 6 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand playlistinfo took 5 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand playlistinfo took 5 milliseconds May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseTrackInfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseTrackInfo May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::servicePushState May 19 08:55:46 volumio-office volumio[1171]: verbose: In UPNP mode May 19 08:55:46 volumio-office volumio[1171]: verbose: STATE SERVICE {"status":"play","position":0,"seek":462,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"7e953fca50d94125ae5704a94525ced5.flac","artist":"Music Assistant","album":null,"uri":"http://192.168.3.181:8097/flow/N2GbHKAX/uuid:3f61d9e8-130c-7166-4b56-2ccf67020293/7e953fca50d94125ae5704a94525ced5.flac","trackType":"flac"} May 19 08:55:46 volumio-office volumio[1171]: verbose: CURRENT POSITION 0 May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState stateService play May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState currentStatus play May 19 08:55:46 volumio-office volumio[1171]: info: Received an update from plugin. extracting info from payload May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::servicePushState May 19 08:55:46 volumio-office volumio[1171]: verbose: In UPNP mode May 19 08:55:46 volumio-office volumio[1171]: verbose: STATE SERVICE {"status":"play","position":0,"seek":714,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"260 Kbps","isStreaming":false,"title":"7e953fca50d94125ae5704a94525ced5.flac","artist":"Music Assistant","album":null,"uri":"http://192.168.3.181:8097/flow/N2GbHKAX/uuid:3f61d9e8-130c-7166-4b56-2ccf67020293/7e953fca50d94125ae5704a94525ced5.flac","trackType":"flac"} May 19 08:55:46 volumio-office volumio[1171]: verbose: CURRENT POSITION 0 May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState stateService play May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState currentStatus play May 19 08:55:46 volumio-office volumio[1171]: info: Received an update from plugin. extracting info from payload May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:46 volumio-office volumio[1171]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 480ms May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:46 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:46 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'name' of undefined May 19 08:55:46 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:46 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:46 volumio-office volumio[1171]: at ControllerYTCR.isCurrentService (/data/plugins/music_service/ytcr/dist/index.js:468:95) May 19 08:55:46 volumio-office volumio[1171]: at MPDPlayer. (/data/plugins/music_service/ytcr/dist/index.js:285:22) May 19 08:55:46 volumio-office volumio[1171]: at MPDPlayer.emit (events.js:327:22) May 19 08:55:46 volumio-office volumio[1171]: at MPDPlayer._Player_setStatusAndEmit (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/Player.js:334:10) May 19 08:55:46 volumio-office volumio[1171]: at runMicrotasks () May 19 08:55:46 volumio-office volumio[1171]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 19 08:55:46 volumio-office volumio[1171]: at async MPDPlayer._MPDPlayer_handleExternalMPDEvent (/data/plugins/music_service/ytcr/dist/lib/MPDPlayer.js:565:9) May 19 08:55:46 volumio-office volumio[1171]: at async MPDSubsystemEventEmitter._MPDSubsystemEventEmitter_handleSystemEvent (/data/plugins/music_service/ytcr/dist/lib/MPDSubsystemEventEmitter.js:135:21) May 19 08:55:46 volumio-office volumio[1171]: (node:1171) 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) May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 10ms May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand status took 10 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 10ms May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand status took 10 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand playlistinfo took 9 milliseconds May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseState May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseTrackInfo May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::servicePushState May 19 08:55:46 volumio-office volumio[1171]: verbose: In UPNP mode May 19 08:55:46 volumio-office volumio[1171]: verbose: STATE SERVICE {"status":"play","position":0,"seek":966,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"269 Kbps","isStreaming":false,"title":"7e953fca50d94125ae5704a94525ced5.flac","artist":"Music Assistant","album":null,"uri":"http://192.168.3.181:8097/flow/N2GbHKAX/uuid:3f61d9e8-130c-7166-4b56-2ccf67020293/7e953fca50d94125ae5704a94525ced5.flac","trackType":"flac"} May 19 08:55:46 volumio-office volumio[1171]: verbose: CURRENT POSITION 0 May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState stateService play May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState currentStatus play May 19 08:55:46 volumio-office volumio[1171]: info: Received an update from plugin. extracting info from payload May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:46 volumio-office volumio[1171]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 17ms May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand playlistinfo took 2 milliseconds May 19 08:55:46 volumio-office volumio[1171]: info: sendMpdCommand playlistinfo took 2 milliseconds May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseTrackInfo May 19 08:55:46 volumio-office volumio[1171]: verbose: ControllerMpd::parseTrackInfo May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::servicePushState May 19 08:55:46 volumio-office volumio[1171]: verbose: In UPNP mode May 19 08:55:46 volumio-office volumio[1171]: verbose: STATE SERVICE {"status":"play","position":0,"seek":966,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"269 Kbps","isStreaming":false,"title":"7e953fca50d94125ae5704a94525ced5.flac","artist":"Music Assistant","album":null,"uri":"http://192.168.3.181:8097/flow/N2GbHKAX/uuid:3f61d9e8-130c-7166-4b56-2ccf67020293/7e953fca50d94125ae5704a94525ced5.flac","trackType":"flac"} May 19 08:55:46 volumio-office volumio[1171]: verbose: CURRENT POSITION 0 May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState stateService play May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState currentStatus play May 19 08:55:46 volumio-office volumio[1171]: info: Received an update from plugin. extracting info from payload May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:46 volumio-office volumio[1171]: info: ControllerMpd::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::servicePushState May 19 08:55:46 volumio-office volumio[1171]: verbose: In UPNP mode May 19 08:55:46 volumio-office volumio[1171]: verbose: STATE SERVICE {"status":"play","position":0,"seek":966,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"269 Kbps","isStreaming":false,"title":"7e953fca50d94125ae5704a94525ced5.flac","artist":"Music Assistant","album":null,"uri":"http://192.168.3.181:8097/flow/N2GbHKAX/uuid:3f61d9e8-130c-7166-4b56-2ccf67020293/7e953fca50d94125ae5704a94525ced5.flac","trackType":"flac"} May 19 08:55:46 volumio-office volumio[1171]: verbose: CURRENT POSITION 0 May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState stateService play May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::syncState currentStatus play May 19 08:55:46 volumio-office volumio[1171]: info: Received an update from plugin. extracting info from payload May 19 08:55:46 volumio-office volumio[1171]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 19 08:55:46 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:46 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:46 volumio-office volumio[1171]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 19 08:55:46 volumio-office volumio[1171]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 15ms May 19 08:55:46 volumio-office volumio[1171]: info: ------------------------------ 14ms May 19 08:55:47 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:47 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. May 19 08:55:47 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:47 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:47 volumio-office go-librespot[2755]: go-librespot daemon starting... May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="app state loaded" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="stored credentials not found" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=info msg="zeroconf server listening on port 37887" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="obtained new client token: AADqTI7pXuCbATi3Ttdn0p3+VuaHeeTzmI3NBM8Sk5NEon4MY51OknlFqHZprOOYfOFjY8qzmtRECs1CrMGvo1ud8dOQZpi818h4q083/syseJTo/FsqcSUsBRSjJl1k0oPfjuQXChyYEvXwjJqdd021NugFYHkrxKuecc7Km18PQpTIylhPhD9ZqWiaAU8K8w9p9ONwUCePA+14kVfXakL2vcbOmPMkS2DksuJyD6PTTJ8p28u7j7Uvuw==" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="completed keyexchange" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=debug msg="completed challenge" May 19 08:55:47 volumio-office go-librespot[2755]: time="2025-05-19T08:55:47-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:47 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:47 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:49 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:49 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:49 volumio-office volumio[1476]: 30 May 19 08:55:49 volumio-office volumio[1476]: % Total % Received % Xferd Average Speed Time Time Time Current May 19 08:55:49 volumio-office volumio[1476]: Dload Upload Total Spent Left Speed May 19 08:55:49 volumio-office volumio[1171]: info: May 19 08:55:49 volumio-office volumio[1171]: ---------------------------- Client requests Volume 30 May 19 08:55:49 volumio-office volumio[1171]: info: VolumeController::SetAlsaVolume30 May 19 08:55:49 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:49 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:49 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:49 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:49 volumio-office volumio[1476]: [158B blob data] May 19 08:55:49 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'name' of undefined May 19 08:55:49 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:49 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:49 volumio-office volumio[1171]: at ControllerYTCR.isCurrentService (/data/plugins/music_service/ytcr/dist/index.js:468:95) May 19 08:55:49 volumio-office volumio[1171]: at /data/plugins/music_service/ytcr/dist/index.js:269:22 May 19 08:55:49 volumio-office volumio[1171]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) May 19 08:55:49 volumio-office volumio[1171]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) May 19 08:55:49 volumio-office volumio[1171]: at Promise._successFn (/volumio/app/index.js:137:16) May 19 08:55:49 volumio-office volumio[1171]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 19 08:55:49 volumio-office volumio[1171]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 19 08:55:49 volumio-office volumio[1171]: (node:1171) 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) May 19 08:55:49 volumio-office volumio[1476]: {"time":1747659349361,"response":"volume Success"}30 May 19 08:55:49 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:49 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:49 volumio-office volumio[1171]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 19 08:55:49 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:49 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:49 volumio-office volumio[1171]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 19 08:55:49 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:55:49 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 19 08:55:49 volumio-office volumio[1171]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 19 08:55:49 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:55:49 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 19 08:55:49 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:55:49 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:55:49 volumio-office volumio[1171]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 19 08:55:49 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:55:49 volumio-office volumio[1171]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 19 08:55:49 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 19 08:55:49 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:55:49 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:55:50 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:50 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. May 19 08:55:50 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:50 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:50 volumio-office go-librespot[2829]: go-librespot daemon starting... May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=debug msg="app state loaded" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=debug msg="stored credentials not found" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:50 volumio-office go-librespot[2829]: time="2025-05-19T08:55:50-04:00" level=info msg="zeroconf server listening on port 39303" May 19 08:55:51 volumio-office go-librespot[2829]: time="2025-05-19T08:55:51-04:00" level=debug msg="obtained new client token: AABt9m5yEy6p1RakaW/7Geqpd0PopWs1c8FIQR7JfRc46XmJZJ8Pkq0Jav1hXBcUNT2SzF9ZUtotS1ANlY4TpIrUTFnfryRmjpBuxOzR5dwGfdVcYVB2BSeV7dJ6VdVWp9jN/M4v/zs3sFT1QQNoD3XnnJBHx2gMQh+fmP6PywbYiT+/7/l9JqtxamB7QjLM0vfdj+NXnX1VuoTW2pGk4GuGi5LDRDxLHtLTQtiGoYAD3Ou/34H6lf4=" May 19 08:55:51 volumio-office go-librespot[2829]: time="2025-05-19T08:55:51-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:51 volumio-office go-librespot[2829]: time="2025-05-19T08:55:51-04:00" level=debug msg="completed keyexchange" May 19 08:55:51 volumio-office go-librespot[2829]: time="2025-05-19T08:55:51-04:00" level=debug msg="completed challenge" May 19 08:55:51 volumio-office go-librespot[2829]: time="2025-05-19T08:55:51-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:51 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:51 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:52 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:52 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:52 volumio-office volumio[1476]: 86 May 19 08:55:52 volumio-office volumio[1476]: % Total % Received % Xferd Average Speed Time Time Time Current May 19 08:55:52 volumio-office volumio[1476]: Dload Upload Total Spent Left Speed May 19 08:55:52 volumio-office volumio[1171]: info: May 19 08:55:52 volumio-office volumio[1171]: ---------------------------- Client requests Volume 86 May 19 08:55:52 volumio-office volumio[1171]: info: VolumeController::SetAlsaVolume86 May 19 08:55:52 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:52 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:52 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:52 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:52 volumio-office volumio[1476]: [158B blob data] May 19 08:55:52 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'name' of undefined May 19 08:55:52 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:52 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:52 volumio-office volumio[1171]: at ControllerYTCR.isCurrentService (/data/plugins/music_service/ytcr/dist/index.js:468:95) May 19 08:55:52 volumio-office volumio[1171]: at /data/plugins/music_service/ytcr/dist/index.js:269:22 May 19 08:55:52 volumio-office volumio[1171]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) May 19 08:55:52 volumio-office volumio[1171]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) May 19 08:55:52 volumio-office volumio[1171]: at Promise._successFn (/volumio/app/index.js:137:16) May 19 08:55:52 volumio-office volumio[1171]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 19 08:55:52 volumio-office volumio[1171]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 19 08:55:52 volumio-office volumio[1171]: (node:1171) 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: 6) May 19 08:55:52 volumio-office volumio[1476]: {"time":1747659352767,"response":"volume Success"}86 May 19 08:55:54 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:54 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. May 19 08:55:54 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:54 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:54 volumio-office go-librespot[2848]: go-librespot daemon starting... May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="app state loaded" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="stored credentials not found" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=info msg="zeroconf server listening on port 38745" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="obtained new client token: AABnH6dhox5WIIsgsLQQPeqATBV0W3ISveqWEv3qiqZdk+1rUHhmlLec3DMegSESbRW5x/DNFd7PnCX+sI8vBMhJrcrble8lXblIxXlTLyJdNG7eLmmb7747vzrEw5ezsmrQsG5HidyKTEJN0Z8f7b/o0eXaVcZw8ZpL6MCxzDnauOBNACiCCPfjzTDCKig6D7ffcbrnWmww3ZXjt397xF7Q7qtZZGlGZhYXJ+aN9XPnvlrwhfrRlJ6fQA==" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="completed keyexchange" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=debug msg="completed challenge" May 19 08:55:54 volumio-office go-librespot[2848]: time="2025-05-19T08:55:54-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:54 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:54 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:55 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:55 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:55 volumio-office volumio[1476]: 26 May 19 08:55:55 volumio-office volumio[1476]: % Total % Received % Xferd Average Speed Time Time Time Current May 19 08:55:55 volumio-office volumio[1476]: Dload Upload Total Spent Left Speed May 19 08:55:55 volumio-office volumio[1171]: info: May 19 08:55:55 volumio-office volumio[1171]: ---------------------------- Client requests Volume 26 May 19 08:55:55 volumio-office volumio[1171]: info: VolumeController::SetAlsaVolume26 May 19 08:55:55 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:55 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:55 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:55 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:55 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'name' of undefined May 19 08:55:55 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:55 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:55 volumio-office volumio[1171]: at ControllerYTCR.isCurrentService (/data/plugins/music_service/ytcr/dist/index.js:468:95) May 19 08:55:55 volumio-office volumio[1171]: at /data/plugins/music_service/ytcr/dist/index.js:269:22 May 19 08:55:55 volumio-office volumio[1171]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) May 19 08:55:55 volumio-office volumio[1171]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) May 19 08:55:55 volumio-office volumio[1171]: at Promise._successFn (/volumio/app/index.js:137:16) May 19 08:55:55 volumio-office volumio[1171]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 19 08:55:55 volumio-office volumio[1171]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 19 08:55:55 volumio-office volumio[1171]: (node:1171) 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: 7) May 19 08:55:55 volumio-office volumio[1476]: [158B blob data] May 19 08:55:55 volumio-office volumio[1476]: {"time":1747659355791,"response":"volume Success"}26 May 19 08:55:57 volumio-office volumio[1476]: 70 May 19 08:55:57 volumio-office volumio[1476]: % Total % Received % Xferd Average Speed Time Time Time Current May 19 08:55:57 volumio-office volumio[1476]: Dload Upload Total Spent Left Speed May 19 08:55:57 volumio-office volumio[1171]: info: May 19 08:55:57 volumio-office volumio[1171]: ---------------------------- Client requests Volume 70 May 19 08:55:57 volumio-office volumio[1171]: info: VolumeController::SetAlsaVolume70 May 19 08:55:57 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:57 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:57 volumio-office volumio[1171]: info: CoreStateMachine::pushState May 19 08:55:57 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:57 volumio-office volumio[1476]: [158B blob data] May 19 08:55:57 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'name' of undefined May 19 08:55:57 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:57 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:57 volumio-office volumio[1171]: at ControllerYTCR.isCurrentService (/data/plugins/music_service/ytcr/dist/index.js:468:95) May 19 08:55:57 volumio-office volumio[1171]: at /data/plugins/music_service/ytcr/dist/index.js:269:22 May 19 08:55:57 volumio-office volumio[1171]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) May 19 08:55:57 volumio-office volumio[1171]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) May 19 08:55:57 volumio-office volumio[1171]: at Promise._successFn (/volumio/app/index.js:137:16) May 19 08:55:57 volumio-office volumio[1171]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 19 08:55:57 volumio-office volumio[1171]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 19 08:55:57 volumio-office volumio[1171]: (node:1171) 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: 8) May 19 08:55:57 volumio-office volumio[1476]: {"time":1747659357148,"response":"volume Success"}70 May 19 08:55:57 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:55:57 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. May 19 08:55:57 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:55:57 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:55:57 volumio-office go-librespot[2897]: go-librespot daemon starting... May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=debug msg="app state loaded" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=debug msg="stored credentials not found" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 19 08:55:57 volumio-office go-librespot[2897]: time="2025-05-19T08:55:57-04:00" level=info msg="zeroconf server listening on port 40937" May 19 08:55:58 volumio-office go-librespot[2897]: time="2025-05-19T08:55:58-04:00" level=debug msg="obtained new client token: AADGjCCiVPBbqWHSeBVofc7BO4Kch0qCKa4vjTxSsrkchh2I53ZproMNddeWVQrgyxKzY7AUhw5KTYX7WoO0WB4USKkxUufNLssC9nUwXhfUupumrp1nruFUhH5Xd5WDnKnF8iYEhwE5EKy/oME4woAU5zC8f6K2xpam1NP6LZvvuCNXtq5IBRn4zZn83WzJPfaRzViBFoAV2GSAKoxwhsMVMslWZZi5tR1/UChev86Tlusb9g6737s=" May 19 08:55:58 volumio-office go-librespot[2897]: time="2025-05-19T08:55:58-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:55:58 volumio-office go-librespot[2897]: time="2025-05-19T08:55:58-04:00" level=debug msg="completed keyexchange" May 19 08:55:58 volumio-office go-librespot[2897]: time="2025-05-19T08:55:58-04:00" level=debug msg="completed challenge" May 19 08:55:58 volumio-office go-librespot[2897]: time="2025-05-19T08:55:58-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:55:58 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:55:58 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:55:58 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:55:58 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:55:59 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:55:59 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:55:59 volumio-office volumio[1171]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 19 08:55:59 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:55:59 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:55:59 volumio-office volumio[1171]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 19 08:55:59 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:55:59 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 19 08:55:59 volumio-office volumio[1171]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 19 08:55:59 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:55:59 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 19 08:55:59 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:55:59 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:55:59 volumio-office volumio[1171]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 19 08:55:59 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:55:59 volumio-office volumio[1171]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 19 08:55:59 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 19 08:55:59 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:55:59 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:55:59 volumio-office volumio[1171]: info: Listing playlists May 19 08:56:01 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:01 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:01 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:01 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. May 19 08:56:01 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:01 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:01 volumio-office go-librespot[2911]: go-librespot daemon starting... May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="app state loaded" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="stored credentials not found" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=info msg="zeroconf server listening on port 35837" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="obtained new client token: AADTZ+wK7tMcIZm7TsT5NY+UWqe/bbL0tWoF0v6J1DYVoOqtT/cEJCbueLfLVO4IgGL3dKw4Vy/MfukaWTXYb6ttQP9m1eYoUvAuL48u5HjESqFfFho3Uq8jCT0w6M84d6jBOW2FEPaLpYOzI5ri/MDts/npAiecedQ55sJK9CxIz/hs/eceFrkYB1YCQ1vxCacs3YUUYJuqYwc3iil8pZyicBXX356BCSVIHW1rhkli3E+xcMkFuFlDOA==" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="completed keyexchange" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=debug msg="completed challenge" May 19 08:56:01 volumio-office go-librespot[2911]: time="2025-05-19T08:56:01-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:01 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:01 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:04 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:04 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:04 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:04 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. May 19 08:56:04 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:04 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:04 volumio-office go-librespot[2927]: go-librespot daemon starting... May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=debug msg="app state loaded" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=debug msg="stored credentials not found" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:04 volumio-office go-librespot[2927]: time="2025-05-19T08:56:04-04:00" level=info msg="zeroconf server listening on port 38453" May 19 08:56:05 volumio-office go-librespot[2927]: time="2025-05-19T08:56:05-04:00" level=debug msg="obtained new client token: AAAbeekO/hx5ZWs/2zNB2ud0c0fPucqBfjfi+ab1yoUNc0kMs3i+afyKeQ1EovWVxixtvxiyC2cu81mmBbaSpwK/1MrylOU8u1ZW+YNhLkEwS/ezYdQBe58WeD9cAkUqhMEz7SYxRWzgmAHORJa42pH4bJ13UmHfY1qP/uIe+zHvC6cJsHSNvB82lvrjCTeUn1AmpnjrW9w5SNSViLAZAER+BxcIYEzEK7udKo5IVmaGBPISbKlsamE=" May 19 08:56:05 volumio-office go-librespot[2927]: time="2025-05-19T08:56:05-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:05 volumio-office go-librespot[2927]: time="2025-05-19T08:56:05-04:00" level=debug msg="completed keyexchange" May 19 08:56:05 volumio-office go-librespot[2927]: time="2025-05-19T08:56:05-04:00" level=debug msg="completed challenge" May 19 08:56:05 volumio-office go-librespot[2927]: time="2025-05-19T08:56:05-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:05 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:05 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:07 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:07 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:08 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:08 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. May 19 08:56:08 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:08 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:08 volumio-office go-librespot[2966]: go-librespot daemon starting... May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="app state loaded" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="stored credentials not found" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=info msg="zeroconf server listening on port 45255" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="obtained new client token: AAAMHbd2ibfJ5bLXAi2OxWxH3TQJXAXlZfKC0VpYVQ6DQS+0Ph7n9rGe10xrmYr2l4CFRfntp6HUV3wyOjXZoSQY7JPK9nOpWrmHR4UMX12Dtfg1ajZJbyi/FhnaSaFSO62vTWzK6ieo8KDQVjJs9C6pOXFFmTX6cPhNQKcdTnn+mRppDlPBloJBgC8vNkMltx2T0+ugIOjtpSrxD8esLO7Rq9vm2kyx0VC2jQGYc9xNQp9yxHnBJ/iujw==" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="completed keyexchange" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=debug msg="completed challenge" May 19 08:56:08 volumio-office go-librespot[2966]: time="2025-05-19T08:56:08-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:08 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:08 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:09 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:56:09 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:56:09 volumio-office volumio[1171]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 19 08:56:09 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:56:09 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:56:09 volumio-office volumio[1171]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 19 08:56:09 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:09 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 19 08:56:09 volumio-office volumio[1171]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 19 08:56:09 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:09 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 19 08:56:09 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:09 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:09 volumio-office volumio[1171]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 19 08:56:09 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:09 volumio-office volumio[1171]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 19 08:56:09 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 19 08:56:09 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:09 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:10 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:10 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:11 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:11 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. May 19 08:56:11 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:11 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:11 volumio-office go-librespot[2985]: go-librespot daemon starting... May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=debug msg="app state loaded" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=debug msg="stored credentials not found" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:11 volumio-office go-librespot[2985]: time="2025-05-19T08:56:11-04:00" level=info msg="zeroconf server listening on port 41321" May 19 08:56:12 volumio-office go-librespot[2985]: time="2025-05-19T08:56:12-04:00" level=debug msg="obtained new client token: AADa8DldLdfoNZ1CD3k3okGf5rjhk00DjoxSvHqtpKTYIaluq+1gJWNOZB3xMwNUrMNPOaL4OYHVgpdlzt2ggNhbu6HXg+1ApRXM13P5wlAmtRlixx0RqQmtYt0HVGIixiDjDzOJ3rspzRhstyWYVkEkdeY90TgNorXgiSCmYQrSrstoyN5JkwsWTWAiDT8Zinj2vgEzmikeXAVgVQxtgSfPAb3VQol0V39PZjzXboCMI2LVLGX5llU=" May 19 08:56:12 volumio-office go-librespot[2985]: time="2025-05-19T08:56:12-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:12 volumio-office go-librespot[2985]: time="2025-05-19T08:56:12-04:00" level=debug msg="completed keyexchange" May 19 08:56:12 volumio-office go-librespot[2985]: time="2025-05-19T08:56:12-04:00" level=debug msg="completed challenge" May 19 08:56:12 volumio-office go-librespot[2985]: time="2025-05-19T08:56:12-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:12 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:12 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:13 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:13 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:15 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:15 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. May 19 08:56:15 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:15 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:15 volumio-office go-librespot[2999]: go-librespot daemon starting... May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="app state loaded" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="stored credentials not found" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=info msg="zeroconf server listening on port 37941" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="obtained new client token: AABYYCUiXiweT2DDtLPgy9gMSpWqPpoU5asMZ/J5Pn5qekMLeEUYTHqzuDpoXz5+WSSERykBNMg2Sz8t11gWKZDsE82XIXpn/7pB/Ett1C5TLd81zpNC6FFGXwZQ3OfJN5oGRwcogyupNa3XpqvHuStn+Fj6CxDXo5FcK0Po9hEZYHhRjKT372tQR77zaI2Eqw/nQpK+gz4oN/rgWzIxCWt/q9qdlMdBjiSYRyJ1YOCtky4/Z0L9bGFc+g==" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="completed keyexchange" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=debug msg="completed challenge" May 19 08:56:15 volumio-office go-librespot[2999]: time="2025-05-19T08:56:15-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:15 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:15 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:16 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:16 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:18 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:18 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. May 19 08:56:18 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:18 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:18 volumio-office go-librespot[3038]: go-librespot daemon starting... May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=debug msg="app state loaded" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=debug msg="stored credentials not found" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:18 volumio-office go-librespot[3038]: time="2025-05-19T08:56:18-04:00" level=info msg="zeroconf server listening on port 33175" May 19 08:56:19 volumio-office go-librespot[3038]: time="2025-05-19T08:56:19-04:00" level=debug msg="obtained new client token: AAAWUHWSL7Fas16zA/ClTRK3i0a3PxooRUTkWgbvoygzWvmw5CI9e42T5A051gu2Xj63l5MuAMYL1qM2MKgDvx/Q4JtC9ucvhxdJIEuaDfWfsdCbb5niEOtDEuxabABhAhXCdmyxbH+GVVKsPgU/CevyjeRuZJq18nM7RM6EPxq8tHKPJdT0ttWFSqezgWl9ykYXX8kjqr/383F5jku/wUCTwbDyR9+H5P08Cxc4sf/BZi5h65bML8Q=" May 19 08:56:19 volumio-office go-librespot[3038]: time="2025-05-19T08:56:19-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:19 volumio-office go-librespot[3038]: time="2025-05-19T08:56:19-04:00" level=debug msg="completed keyexchange" May 19 08:56:19 volumio-office go-librespot[3038]: time="2025-05-19T08:56:19-04:00" level=debug msg="completed challenge" May 19 08:56:19 volumio-office go-librespot[3038]: time="2025-05-19T08:56:19-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:19 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:19 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:19 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:19 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:19 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:56:19 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:56:19 volumio-office volumio[1171]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 19 08:56:19 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:56:19 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:56:19 volumio-office volumio[1171]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 19 08:56:19 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:19 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 19 08:56:19 volumio-office volumio[1171]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 19 08:56:19 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:19 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 19 08:56:19 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:19 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:19 volumio-office volumio[1171]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 19 08:56:19 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:19 volumio-office volumio[1171]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 19 08:56:19 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 19 08:56:19 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:19 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:19 volumio-office volumio[1171]: info: Listing playlists May 19 08:56:19 volumio-office volumio[1171]: info: Listing playlists May 19 08:56:22 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:22 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. May 19 08:56:22 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:22 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:22 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:22 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:22 volumio-office go-librespot[3054]: go-librespot daemon starting... May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="app state loaded" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="stored credentials not found" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=info msg="zeroconf server listening on port 35139" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="obtained new client token: AADrSt0f2whCPc215o6b9F7wxFd+e0Fd+Ui/7oqsuUC+GZS03IYu9ywY7AVO3pAXnNiWyAB2s+LDTJzakX1lLuv6L7ecoewuET3OsNPDjpQsekh3caKzNblyfNG4/Q8ijiSdg4Y+3zDBF5oa1QtO+b0qWIJR8oxqEqdtjMkk4rl+/qriJfECfF0ys7v7xk+4YXpTIC+PRpGP1Bvn/RwO26dT9Z0Dxe8OtR72pGzJ8merlCkY8fyeVlfJMA==" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="completed keyexchange" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=debug msg="completed challenge" May 19 08:56:22 volumio-office go-librespot[3054]: time="2025-05-19T08:56:22-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:22 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:22 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:25 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:25 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:25 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:25 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. May 19 08:56:25 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:25 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:25 volumio-office go-librespot[3070]: go-librespot daemon starting... May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=debug msg="app state loaded" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=debug msg="stored credentials not found" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:25 volumio-office go-librespot[3070]: time="2025-05-19T08:56:25-04:00" level=info msg="zeroconf server listening on port 38653" May 19 08:56:26 volumio-office go-librespot[3070]: time="2025-05-19T08:56:26-04:00" level=debug msg="obtained new client token: AAAmqWGHQAJQiaPsA7u/KnqVLl1Mbz+z5UR9x8+1swWiNXfl4AoZWabsVsNv7DTqFHzgJ2ZUShoPDWUv5aOVbiC7y41gvM+IQUmfj284V8v9JBLhXrFTRnFCb1EKFEQSBVbqNnRXP/QI4ZRnGdG2m8akdotVZ0vQLGsSLXy2irNZ1/C5DBDQA/0S7mJ/UUy+5R8pjL1Ao2pF2MPaszuf9CKUMHtXUtGKswk8sSw6y2qp/ImmBXAj4r8=" May 19 08:56:26 volumio-office go-librespot[3070]: time="2025-05-19T08:56:26-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:26 volumio-office go-librespot[3070]: time="2025-05-19T08:56:26-04:00" level=debug msg="completed keyexchange" May 19 08:56:26 volumio-office go-librespot[3070]: time="2025-05-19T08:56:26-04:00" level=debug msg="completed challenge" May 19 08:56:26 volumio-office go-librespot[3070]: time="2025-05-19T08:56:26-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:26 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:26 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:28 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:28 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:29 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:29 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. May 19 08:56:29 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:29 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:29 volumio-office go-librespot[3111]: go-librespot daemon starting... May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="app state loaded" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="stored credentials not found" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=info msg="zeroconf server listening on port 45407" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="obtained new client token: AADQJKqjM+/FcwTZBoPqcZzGHRFH3llpxjUv6z8u/fWu93NfHk11IvNYzpO7o5W4N4tJr7Wx5MRH/C3+ze1hnxJtoNrdWAnn1LGjfz4+sQ7hwRc6s/CVUI8jnnnW/6eY3XVYhSBm5g0GwD11HzE1hDDhz08R5LNizWRif9Yc7n595CxikI7Q6hA6Ysy+L+j2s7oi+Yi2PD0cneoUbIRpkNOQon2hbuwb3IaqGTNQmvHLM1x0cy//W2829w==" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="completed keyexchange" May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=debug msg="completed challenge" May 19 08:56:29 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:56:29 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:56:29 volumio-office volumio[1171]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 19 08:56:29 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:56:29 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:56:29 volumio-office volumio[1171]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 19 08:56:29 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:29 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 19 08:56:29 volumio-office volumio[1171]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 19 08:56:29 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:29 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 19 08:56:29 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:29 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:29 volumio-office volumio[1171]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 19 08:56:29 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:29 volumio-office volumio[1171]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 19 08:56:29 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 19 08:56:29 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:29 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:29 volumio-office go-librespot[3111]: time="2025-05-19T08:56:29-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:29 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:29 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:31 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:31 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:32 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:32 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. May 19 08:56:32 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:32 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:32 volumio-office go-librespot[3128]: go-librespot daemon starting... May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=debug msg="app state loaded" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=debug msg="stored credentials not found" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 19 08:56:32 volumio-office go-librespot[3128]: time="2025-05-19T08:56:32-04:00" level=info msg="zeroconf server listening on port 43091" May 19 08:56:33 volumio-office go-librespot[3128]: time="2025-05-19T08:56:33-04:00" level=debug msg="obtained new client token: AADxouBhlgrMg/zq7X6cKPM4VJ7f9CsILRTbLYIJUXxsbGtKlskbRYD62JdVcoN4pIlq7yN+XkNfpv+PYgViGWKcvaSO+B3DFVeAQlC2Ut57BviFLZZIJ7QEcxKVConMytUqJMJ1iwxzpwoqDDM501MfjsR5TZHfIKz+D2P8lp46NIMspJ66hNJTehzkF21IvtI7MdaxN3GZ+G2s/XOcBZqxq6/WuNl9eI9Qx3GYxzfSgHZWNffqa7E=" May 19 08:56:33 volumio-office go-librespot[3128]: time="2025-05-19T08:56:33-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:33 volumio-office go-librespot[3128]: time="2025-05-19T08:56:33-04:00" level=debug msg="completed keyexchange" May 19 08:56:33 volumio-office go-librespot[3128]: time="2025-05-19T08:56:33-04:00" level=debug msg="completed challenge" May 19 08:56:33 volumio-office go-librespot[3128]: time="2025-05-19T08:56:33-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:33 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:33 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:34 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:34 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:36 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:36 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. May 19 08:56:36 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:36 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:36 volumio-office go-librespot[3145]: go-librespot daemon starting... May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="app state loaded" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="stored credentials not found" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=info msg="zeroconf server listening on port 45199" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="obtained new client token: AACtEeJ2VMZyrClKqvrLVo9VWSia2ttpqNRXZ44wLR7MHXtoLU1ntyXY5SS5+Dt+67LdzprEJsjs7y4Lr3+5CjqJgCAavlZwK391lD0kkm14mkK0HyGs4zh/tdHoqPl8pb85ZVmxwpIeaovcaWSB92LZn8/9j7IScW6ieIUheRbmDVIYPoun+BzTsCNy4cJgE47mvYSja79oJMmuP9XZuUrQEUGEANFqSqidvGRpRMzH7NuxiHPFxr4Prw==" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="completed keyexchange" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=debug msg="completed challenge" May 19 08:56:36 volumio-office go-librespot[3145]: time="2025-05-19T08:56:36-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:36 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:36 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:37 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:37 volumio-office volumio[1171]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:39 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:56:39 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:56:39 volumio-office volumio[1171]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 19 08:56:39 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:56:39 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:56:39 volumio-office volumio[1171]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 19 08:56:39 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:39 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 19 08:56:39 volumio-office volumio[1171]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 19 08:56:39 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:39 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 19 08:56:39 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:39 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:39 volumio-office volumio[1171]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 19 08:56:39 volumio-office volumio[1171]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 19 08:56:39 volumio-office volumio[1171]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 19 08:56:39 volumio-office volumio[1171]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 19 08:56:39 volumio-office volumio[1171]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 19 08:56:39 volumio-office volumio[1171]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 19 08:56:39 volumio-office volumio[1171]: info: Listing playlists May 19 08:56:39 volumio-office volumio[1171]: info: Listing playlists May 19 08:56:39 volumio-office systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 19 08:56:39 volumio-office systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. May 19 08:56:39 volumio-office systemd[1]: Stopped go-librespot Daemon. May 19 08:56:39 volumio-office systemd[1]: Started go-librespot Daemon. May 19 08:56:39 volumio-office go-librespot[3184]: go-librespot daemon starting... May 19 08:56:39 volumio-office go-librespot[3184]: time="2025-05-19T08:56:39-04:00" level=info msg="running go-librespot 0.2.0" May 19 08:56:39 volumio-office go-librespot[3184]: time="2025-05-19T08:56:39-04:00" level=debug msg="app state loaded" May 19 08:56:39 volumio-office go-librespot[3184]: time="2025-05-19T08:56:39-04:00" level=debug msg="stored credentials not found" May 19 08:56:39 volumio-office go-librespot[3184]: time="2025-05-19T08:56:39-04:00" level=info msg="api server listening on 127.0.0.1:9879" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=info msg="zeroconf server listening on port 35281" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="obtained new client token: AAA3xC0sOAmtiqQTTaKCqIGpGHAoc7qzUJ6bPjTpaQ7j/akr9MafXbANqzJEb/o1K7S/klbfrBEqG6D6zJs1ZQCAAL7KcC+cnKhDP7XFaKjwo4AYohgv4DUy/CsQkqTwrHuDeSR/Ap6KQkOba/s9de27KZBoNNQvCafJYiGPcLQIDUf4wkl94SJUauogdZS927L2hWDw6nKJ/QPDIoYb7g4nTW9RIif3TWkPsrLWMKTsM26gBIuFGCI=" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" May 19 08:56:40 volumio-office volumio[1171]: info: Initializing connection to go-librespot Websocket May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="new websocket client" May 19 08:56:40 volumio-office volumio[1171]: info: Connection to go-librespot Websocket established May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="completed keyexchange" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=debug msg="completed challenge" May 19 08:56:40 volumio-office go-librespot[3184]: time="2025-05-19T08:56:40-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " May 19 08:56:40 volumio-office systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 19 08:56:40 volumio-office systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 19 08:56:40 volumio-office volumio[1171]: info: Connection to go-librespot Websocket closed May 19 08:56:43 volumio-office volumio[1171]: info: Getting Spotify volume May 19 08:56:43 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 19 08:56:43 volumio-office volumio[1171]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 19 08:56:43 volumio-office volumio[1171]: (node:1171) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 9) May 19 08:56:43 volumio-office volumio[1171]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 19 08:56:43 volumio-office volumio[1171]: info: CoreCommandRouter::volumioGetState May 19 08:56:43 volumio-office volumio[1171]: info: CorePlayQueue::getTrack 0 May 19 08:56:43 volumio-office volumio[1171]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 19 08:56:43 volumio-office volumio[1171]: TypeError: Cannot read property 'name' of undefined May 19 08:56:43 volumio-office volumio[1171]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 19 08:56:43 volumio-office volumio[1171]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 19 08:56:43 volumio-office volumio[1171]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:58:38) May 19 08:56:43 volumio-office volumio[1171]: at Socket.emit (events.js:315:20) May 19 08:56:43 volumio-office volumio[1171]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 19 08:56:43 volumio-office volumio[1171]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 19 08:56:43 volumio-office volumio[1171]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 19 08:56:43 volumio-office sudo[3210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-19 08:55 May 19 08:56:43 volumio-office sudo[3210]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"