-- Logs begin at Tue 2025-09-02 17:36:23 CEST, end at Tue 2025-09-02 18:52:12 CEST. -- Sep 02 18:51:00 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:00 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351015. Sep 02 18:51:00 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:00 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:00 volumiunten go-librespot[20350]: go-librespot daemon starting... Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="app state loaded" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=info msg="zeroconf server listening on port 46829" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="obtained new client token: AADbFCd7pS2rTdddRU4UPEayolWVBK9cvmYHzpZjRyOx85tkd+ME2/Si08D7pbK2MMs/dfXPgx+8JMRGKy8mYofqhlipM+SXKVY3MF4kpQnmLv8yQ9ghwKq0sbB+qBVqaSK2//0n5vZKwR2SwsfNmOPnQdNwCn4PvWDfbsCbdYYaUyG6wQIdjuglelEGhqjsH5e9qyp8MxHfenq+UKTboIy05K51cZkS/KNLvjO3oTUN/Flq0UqvWLc=" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02:00" level=debug msg="completed challenge" Sep 02 18:51:00 volumiunten go-librespot[20350]: time="2025-09-02T18:51:00+02: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 " Sep 02 18:51:00 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:00 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:01 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:01 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:03 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:03 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351016. Sep 02 18:51:03 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:03 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:03 volumiunten go-librespot[20372]: go-librespot daemon starting... Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="app state loaded" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=info msg="zeroconf server listening on port 35889" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="obtained new client token: AADgVkdcXCjH3vnBdz12DMGBiUfUzssLIv3zqoXfy/KYXQJcKgWhAA6IhavCBPO8RmtOF5Oagmu7fzvIaJcmyxq3hA8FTe/Xsu/rV0yq40X9RgE7UgYOzVC3HwSmOPXhkMRD/FRkE6/Y5a9qjo0dDBaeW3+mnnF9UWdrw4NkWOAwKyLv5uhargMzmBF60T05HEHJFewHC/31xxGJObUqp9C1r3/gqeEs3sdnPDTuLbSeMHjjl1bHfks=" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02:00" level=debug msg="completed challenge" Sep 02 18:51:04 volumiunten go-librespot[20372]: time="2025-09-02T18:51:04+02: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 " Sep 02 18:51:04 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:04 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:04 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:04 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:07 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:07 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:07 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:07 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351017. Sep 02 18:51:07 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:07 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:07 volumiunten go-librespot[20380]: go-librespot daemon starting... Sep 02 18:51:07 volumiunten go-librespot[20380]: time="2025-09-02T18:51:07+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:07 volumiunten go-librespot[20380]: time="2025-09-02T18:51:07+02:00" level=debug msg="app state loaded" Sep 02 18:51:07 volumiunten go-librespot[20380]: time="2025-09-02T18:51:07+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:07 volumiunten go-librespot[20380]: time="2025-09-02T18:51:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=info msg="zeroconf server listening on port 36783" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="obtained new client token: AAA6Ds32MuhgfC5YW1YvYHQcfOUay/NTFhB7xvkF58jhyw2bwyq8s42g0ZZiigTaQYBG7AdhMBVYgl6DTz7bcuA+EszdBRALwq90FPMoQDPcpb59DdRybHu0P9W8R/XpWn2NVkRWPwqlr6UsKeOn3PukA1+OkqP5CHjmlccTpUSaTUh1mZQn/8KkSMbtVrw2etP+hvZZJbv3zio+ARQrrpOUighxLSzS3NIKlvfWEc+U3TZ/Vw86" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02:00" level=debug msg="completed challenge" Sep 02 18:51:08 volumiunten go-librespot[20380]: time="2025-09-02T18:51:08+02: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 " Sep 02 18:51:08 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:08 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:10 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:10 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:11 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:11 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351018. Sep 02 18:51:11 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:11 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:11 volumiunten go-librespot[20389]: go-librespot daemon starting... Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=debug msg="app state loaded" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:11 volumiunten go-librespot[20389]: time="2025-09-02T18:51:11+02:00" level=info msg="zeroconf server listening on port 38005" Sep 02 18:51:12 volumiunten go-librespot[20389]: time="2025-09-02T18:51:12+02:00" level=debug msg="obtained new client token: AABiCQOJj0aOt6rKlQZhvNELsCRmqZi9EL1bLQPBJBvqxkKb8jXVRjCwAWYccQQ+VH7PojUE39/+gUqS9E/RfcA3OhlCrW/hkjfijqj5TVbc78451U0HbC+qQtbgdTyXAq7gvWg6vHRr0egHHIsoNw19p346zkGmEqOoJebHO22exb99wADt/kqS7xt4Z6f9O3KPl/pBdqcVEmNRHQyZaQsRWHNFJwdSVuj7Pkaunbnqd513enjg4LA=" Sep 02 18:51:12 volumiunten go-librespot[20389]: time="2025-09-02T18:51:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:12 volumiunten go-librespot[20389]: time="2025-09-02T18:51:12+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:12 volumiunten go-librespot[20389]: time="2025-09-02T18:51:12+02:00" level=debug msg="completed challenge" Sep 02 18:51:12 volumiunten go-librespot[20389]: time="2025-09-02T18:51:12+02: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 " Sep 02 18:51:12 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:12 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:13 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:13 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:15 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:15 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351019. Sep 02 18:51:15 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:15 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:15 volumiunten go-librespot[20412]: go-librespot daemon starting... Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="app state loaded" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=info msg="zeroconf server listening on port 41275" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="obtained new client token: AABYn8J6z4VCEkwfJehg3MTZfZ/o1XYtISiVhSKY43Km6nqtjxWSX6ZE5bOFBl/mQ29XUJ3GSl3MIoiUU5lR6BN/Yj5m3TbXQ1XP4iFsB2AtdyGPZHjivy+DZBp/KioDN4uXw0bi9Uz3gNDbVB+JaEVbTfYkiha9OpaZcNddc5rvvuBbXuDS5E6xNpz0MR7Q8mZIBhX7BCLKdJeVlsut0DA3Gb0JoS8R8/Cv5YurI1VGe0Zte50X+ZU=" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02:00" level=debug msg="completed challenge" Sep 02 18:51:15 volumiunten go-librespot[20412]: time="2025-09-02T18:51:15+02: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 " Sep 02 18:51:15 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:15 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:16 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:16 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:18 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:18 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351020. Sep 02 18:51:18 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:19 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:19 volumiunten go-librespot[20420]: go-librespot daemon starting... Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="app state loaded" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=info msg="zeroconf server listening on port 35131" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="obtained new client token: AADSBBEr9MwqtxSd86ChODQZjQSXgk4Rkvj5PCXUCgwe1g89RVM70CW8J/UfE/GdTFcQtwFDJK2NZoBwUrDiizqYr7d3m+3AGZ1aCALIO6QS7JeZaoHGQ/t5V1zdjIoPFuLmhkyW8n/kwQ0MIR/L/3KMhbirHcVgxs4TdDKeVBj5FrwNfAnLwkZgVAB58hFPKfSN/BwRpbj+n3LQZblPFQhqUuQUshCVi3tNPBmbYqn8cZNHxi1qQWQ=" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02:00" level=debug msg="completed challenge" Sep 02 18:51:19 volumiunten go-librespot[20420]: time="2025-09-02T18:51:19+02: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 " Sep 02 18:51:19 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:19 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:19 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:19 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:22 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:22 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351021. Sep 02 18:51:22 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:22 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:22 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:22 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:22 volumiunten go-librespot[20445]: go-librespot daemon starting... Sep 02 18:51:22 volumiunten go-librespot[20445]: time="2025-09-02T18:51:22+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:22 volumiunten go-librespot[20445]: time="2025-09-02T18:51:22+02:00" level=debug msg="app state loaded" Sep 02 18:51:22 volumiunten go-librespot[20445]: time="2025-09-02T18:51:22+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:22 volumiunten go-librespot[20445]: time="2025-09-02T18:51:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=info msg="zeroconf server listening on port 46177" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="obtained new client token: AACTelzYF8Xe+Ys7qLORP42Z58lXJQHck0VerkI8ic/+wVQznRcWkOKFOQJWxKSa4S8L2v3/qD1eaGRL/FmD/pjgS77F+W8q8UTyhglE4dkcmk3lm/w4iBfS6tEeSHtpzCqVweXkciydQtxAyWJMatTUnmiMQe/iaRnNtm49hp83OdJdFUDHreSmnwgPpalfnD3ih1tFik82dOFxwDLGqIKW5vbtdiGreN0baQUr9BD49QqMXdaO" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02:00" level=debug msg="completed challenge" Sep 02 18:51:23 volumiunten go-librespot[20445]: time="2025-09-02T18:51:23+02: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 " Sep 02 18:51:23 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:23 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:24 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 18:51:24 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 18:51:24 volumiunten volumio[670]: info: Discovery: Getting this device information Sep 02 18:51:24 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:51:24 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 18:51:25 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:25 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:26 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:26 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351022. Sep 02 18:51:26 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:26 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:26 volumiunten go-librespot[20453]: go-librespot daemon starting... Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=debug msg="app state loaded" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:26 volumiunten go-librespot[20453]: time="2025-09-02T18:51:26+02:00" level=info msg="zeroconf server listening on port 36355" Sep 02 18:51:27 volumiunten go-librespot[20453]: time="2025-09-02T18:51:27+02:00" level=debug msg="obtained new client token: AABwiPcVHsAKQEjdhvWm6JNQyAofUhzFBqeXr1jTaES+eTEVDqBS0irAlgWMTctTNNXPafykCZQf16dgFEX8QkQFqGhjc3K62lkKd/z9wUFFVoMdV0fFbO/u4d+ov8nEiKDkuX5QH1LHUMRWUdnwPqtBK9TpNbwBw/oBmZYgoJMFmFt/n7xROHTdiTmgJ2rE9guLdNkhxsLOEiW7TVzxCQczCihli8LNu75P6inoqJT41apu4k6q" Sep 02 18:51:27 volumiunten go-librespot[20453]: time="2025-09-02T18:51:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:27 volumiunten go-librespot[20453]: time="2025-09-02T18:51:27+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:27 volumiunten go-librespot[20453]: time="2025-09-02T18:51:27+02:00" level=debug msg="completed challenge" Sep 02 18:51:27 volumiunten go-librespot[20453]: time="2025-09-02T18:51:27+02: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 " Sep 02 18:51:27 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:27 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:28 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:28 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:30 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:30 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351023. Sep 02 18:51:30 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:30 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:30 volumiunten go-librespot[20461]: go-librespot daemon starting... Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="app state loaded" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=info msg="zeroconf server listening on port 37413" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="obtained new client token: AAAl0//pKu4aqUNFANQlPFiXGvlqLL5yv8Iy+NwQVlbDFkPOIwHNJv2J31q9lIjNWZA7vMjnH+QiGAs5J/4g9PjMbT3gDkCNpD+gHrsXKNclnmLHJRkir6IMjKl9VD0E/TOc4lhLfXDpbLP2ZMVl6Bgx5fXfzi7TzlK6vDjdD5ZJK124a+qudPsMOGsKbbflskEIh/lcCXni7fl06PWvntyYRN/Klv0rKhOUN6JUvNI4354bezW5Qzc=" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02:00" level=debug msg="completed challenge" Sep 02 18:51:30 volumiunten go-librespot[20461]: time="2025-09-02T18:51:30+02: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 " Sep 02 18:51:30 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:30 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:31 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:31 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:33 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:33 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351024. Sep 02 18:51:33 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:33 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:33 volumiunten go-librespot[20484]: go-librespot daemon starting... Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="app state loaded" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=info msg="zeroconf server listening on port 34963" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="obtained new client token: AABSOmT/XTRD8kzZ9dWjbEmvs8+SDFUVTWDpbXXCa01P3vRQFxIYNciUVAdOZUqmmeGLDbFYO3MnLQ5aaQotNKgYPHh97qQymst3PFJ6FTRGS5eXg30TMSNMnijvYJWLopu2MMWUkffUVC88Dz81r6ahZu59mIdTFsjn5MFVvehfx5L/3bmsKzpUf0BdKuFH2NoPh8OSTN9BD8ip1+tr+cRkiVbjV+iSI1Nnfrtz+siUyes7AXIRnf8=" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02:00" level=debug msg="completed challenge" Sep 02 18:51:34 volumiunten go-librespot[20484]: time="2025-09-02T18:51:34+02: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 " Sep 02 18:51:34 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:34 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:34 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:34 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:37 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:37 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351025. Sep 02 18:51:37 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:37 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:37 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:37 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:37 volumiunten go-librespot[20492]: go-librespot daemon starting... Sep 02 18:51:37 volumiunten go-librespot[20492]: time="2025-09-02T18:51:37+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:37 volumiunten go-librespot[20492]: time="2025-09-02T18:51:37+02:00" level=debug msg="app state loaded" Sep 02 18:51:37 volumiunten go-librespot[20492]: time="2025-09-02T18:51:37+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:37 volumiunten go-librespot[20492]: time="2025-09-02T18:51:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=info msg="zeroconf server listening on port 41921" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="obtained new client token: AAB02d6YbJYgvW6lmTuR+S5uF+61tIJdNlGiDrJ9j7iwCkx9HxqCtIlAVIwoHDLv3FeVlAe/Zt8MEF1ksbafM1L0dz2sWbIjuleR4KnLVKw0qJ7znFcIILTcAEhhYuEt97/Y/p8dPeJxsiEFqEj9vR+SqhgkjuFOFz6fOJvJioacUZtTrsvPtwv5piJiO0EC14+8SqeN0psHnBUMnSXm506lw8yrRA9+OW5+hxZFvRkcsIHKxUoK" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02:00" level=debug msg="completed challenge" Sep 02 18:51:38 volumiunten go-librespot[20492]: time="2025-09-02T18:51:38+02: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 " Sep 02 18:51:38 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:38 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:39 volumiunten volumio[670]: info: Sep 02 18:51:39 volumiunten volumio[670]: ---------------------------- MPD announces system playlist update Sep 02 18:51:39 volumiunten volumio[670]: info: Ignoring MPD Status Update Sep 02 18:51:39 volumiunten volumio[670]: info: Sep 02 18:51:39 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:51:39 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:51:39 volumiunten volumio[670]: info: Sep 02 18:51:39 volumiunten volumio[670]: ---------------------------- MPD announces system playlist update Sep 02 18:51:39 volumiunten volumio[670]: info: Ignoring MPD Status Update Sep 02 18:51:39 volumiunten volumio[670]: info: Sep 02 18:51:39 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:51:39 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:51:39 volumiunten volumio[670]: info: Sep 02 18:51:39 volumiunten volumio[670]: ---------------------------- MPD announces system playlist update Sep 02 18:51:39 volumiunten volumio[670]: info: Ignoring MPD Status Update Sep 02 18:51:39 volumiunten volumio[670]: info: Sep 02 18:51:39 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:51:39 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:51:39 volumiunten volumio[670]: info: ------------------------------ 12ms Sep 02 18:51:39 volumiunten volumio[670]: info: sendMpdCommand status took 11 milliseconds Sep 02 18:51:39 volumiunten volumio[670]: info: ------------------------------ 11ms Sep 02 18:51:39 volumiunten volumio[670]: info: sendMpdCommand status took 9 milliseconds Sep 02 18:51:39 volumiunten volumio[670]: info: ------------------------------ 9ms Sep 02 18:51:39 volumiunten volumio[670]: info: sendMpdCommand status took 6 milliseconds Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:51:39 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 02 18:51:39 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 02 18:51:39 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:51:39 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:51:39 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:51:39 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:51:39 volumiunten volumio[670]: verbose: STATE SERVICE {"status":"play","position":0,"seek":486014190,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Muse - Unravelling","artist":"ROCK ANTENNE","album":null,"uri":"http://stream.rockantenne.de/rockantenne/stream/mp3?aw_0_1st.playerid=tunein.com","trackType":"com"} Sep 02 18:51:39 volumiunten volumio[670]: verbose: CURRENT POSITION 0 Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::syncState stateService play Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::syncState currentStatus play Sep 02 18:51:39 volumiunten volumio[670]: info: Received an update from plugin. extracting info from payload Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:39 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:51:39 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:51:39 volumiunten volumio[670]: verbose: STATE SERVICE {"status":"play","position":0,"seek":486014190,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Muse - Unravelling","artist":"ROCK ANTENNE","album":null,"uri":"http://stream.rockantenne.de/rockantenne/stream/mp3?aw_0_1st.playerid=tunein.com","trackType":"com"} Sep 02 18:51:39 volumiunten volumio[670]: verbose: CURRENT POSITION 0 Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::syncState stateService play Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::syncState currentStatus play Sep 02 18:51:39 volumiunten volumio[670]: info: Received an update from plugin. extracting info from payload Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:39 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:51:39 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:51:39 volumiunten volumio[670]: verbose: STATE SERVICE {"status":"play","position":0,"seek":486014190,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Muse - Unravelling","artist":"ROCK ANTENNE","album":null,"uri":"http://stream.rockantenne.de/rockantenne/stream/mp3?aw_0_1st.playerid=tunein.com","trackType":"com"} Sep 02 18:51:39 volumiunten volumio[670]: verbose: CURRENT POSITION 0 Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::syncState stateService play Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::syncState currentStatus play Sep 02 18:51:39 volumiunten volumio[670]: info: Received an update from plugin. extracting info from payload Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:39 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:39 volumiunten volumio[670]: info: ------------------------------ 72ms Sep 02 18:51:39 volumiunten volumio[670]: info: ------------------------------ 71ms Sep 02 18:51:39 volumiunten volumio[670]: info: ------------------------------ 69ms Sep 02 18:51:39 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:39 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:39 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:39 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:39 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:39 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:39 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:39 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:39 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:39 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:39 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:39 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:40 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:40 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:41 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:41 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351026. Sep 02 18:51:41 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:41 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:41 volumiunten go-librespot[20503]: go-librespot daemon starting... Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=debug msg="app state loaded" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:41 volumiunten go-librespot[20503]: time="2025-09-02T18:51:41+02:00" level=info msg="zeroconf server listening on port 38115" Sep 02 18:51:42 volumiunten go-librespot[20503]: time="2025-09-02T18:51:42+02:00" level=debug msg="obtained new client token: AACkRe7MEPaLAhdMszs2EpbaveS7ihX3ne/gXXdCBC2NMo8gLzVCruziIJ8ceK5uwJVZvtLMvLLfoaDhCLBieb/h92U/fgVuWxDDM1oDwOEgaVddEPXeO3BxXKyDl17aRoTxP6n8b7G5VZE9j+V+0ar9DhSOPO4647+FWrANhI2Ut0iBFALrJS02hwSGbGEy7B1RHrXNmqAk+HUDwjgMpIZybnJyISb6VGfnCCsTwoB4x18cyA==" Sep 02 18:51:42 volumiunten go-librespot[20503]: time="2025-09-02T18:51:42+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Sep 02 18:51:42 volumiunten go-librespot[20503]: time="2025-09-02T18:51:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 02 18:51:42 volumiunten go-librespot[20503]: time="2025-09-02T18:51:42+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:42 volumiunten go-librespot[20503]: time="2025-09-02T18:51:42+02:00" level=debug msg="completed challenge" Sep 02 18:51:42 volumiunten go-librespot[20503]: time="2025-09-02T18:51:42+02: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 " Sep 02 18:51:42 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:42 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:42 volumiunten volumio[670]: info: Sep 02 18:51:42 volumiunten volumio[670]: ---------------------------- MPD announces system playlist update Sep 02 18:51:42 volumiunten volumio[670]: info: Ignoring MPD Status Update Sep 02 18:51:42 volumiunten volumio[670]: info: Sep 02 18:51:42 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:51:42 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:51:42 volumiunten volumio[670]: info: Sep 02 18:51:42 volumiunten volumio[670]: ---------------------------- MPD announces system playlist update Sep 02 18:51:42 volumiunten volumio[670]: info: Ignoring MPD Status Update Sep 02 18:51:42 volumiunten volumio[670]: info: Sep 02 18:51:42 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:51:42 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:51:42 volumiunten volumio[670]: info: Sep 02 18:51:42 volumiunten volumio[670]: ---------------------------- MPD announces system playlist update Sep 02 18:51:42 volumiunten volumio[670]: info: Ignoring MPD Status Update Sep 02 18:51:42 volumiunten volumio[670]: info: Sep 02 18:51:42 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:51:42 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:51:42 volumiunten volumio[670]: info: ------------------------------ 13ms Sep 02 18:51:42 volumiunten volumio[670]: info: sendMpdCommand status took 12 milliseconds Sep 02 18:51:42 volumiunten volumio[670]: info: ------------------------------ 11ms Sep 02 18:51:42 volumiunten volumio[670]: info: sendMpdCommand status took 10 milliseconds Sep 02 18:51:42 volumiunten volumio[670]: info: ------------------------------ 9ms Sep 02 18:51:42 volumiunten volumio[670]: info: sendMpdCommand status took 6 milliseconds Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:51:42 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 02 18:51:42 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 02 18:51:42 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:51:42 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:51:42 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:51:42 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:51:42 volumiunten volumio[670]: verbose: STATE SERVICE {"status":"play","position":0,"seek":486017193,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Muse - Unravelling","artist":"ROCK ANTENNE","album":null,"uri":"http://stream.rockantenne.de/rockantenne/stream/mp3?aw_0_1st.playerid=tunein.com","trackType":"com"} Sep 02 18:51:42 volumiunten volumio[670]: verbose: CURRENT POSITION 0 Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::syncState stateService play Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::syncState currentStatus play Sep 02 18:51:42 volumiunten volumio[670]: info: Received an update from plugin. extracting info from payload Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:42 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:51:42 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:51:42 volumiunten volumio[670]: verbose: STATE SERVICE {"status":"play","position":0,"seek":486017193,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Muse - Unravelling","artist":"ROCK ANTENNE","album":null,"uri":"http://stream.rockantenne.de/rockantenne/stream/mp3?aw_0_1st.playerid=tunein.com","trackType":"com"} Sep 02 18:51:42 volumiunten volumio[670]: verbose: CURRENT POSITION 0 Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::syncState stateService play Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::syncState currentStatus play Sep 02 18:51:42 volumiunten volumio[670]: info: Received an update from plugin. extracting info from payload Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:42 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:51:42 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:51:42 volumiunten volumio[670]: verbose: STATE SERVICE {"status":"play","position":0,"seek":486017193,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Muse - Unravelling","artist":"ROCK ANTENNE","album":null,"uri":"http://stream.rockantenne.de/rockantenne/stream/mp3?aw_0_1st.playerid=tunein.com","trackType":"com"} Sep 02 18:51:42 volumiunten volumio[670]: verbose: CURRENT POSITION 0 Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::syncState stateService play Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::syncState currentStatus play Sep 02 18:51:42 volumiunten volumio[670]: info: Received an update from plugin. extracting info from payload Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:51:42 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:51:42 volumiunten volumio[670]: info: ------------------------------ 75ms Sep 02 18:51:42 volumiunten volumio[670]: info: ------------------------------ 74ms Sep 02 18:51:42 volumiunten volumio[670]: info: ------------------------------ 73ms Sep 02 18:51:42 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:42 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:42 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:42 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:42 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:42 volumiunten volumio[670]: info: [ASDebug] CurState: play PrevState: play Sep 02 18:51:42 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:42 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:42 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:42 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:42 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:42 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:43 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:43 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:45 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:45 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351027. Sep 02 18:51:45 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:45 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:45 volumiunten go-librespot[20563]: go-librespot daemon starting... Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=debug msg="app state loaded" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:45 volumiunten go-librespot[20563]: time="2025-09-02T18:51:45+02:00" level=info msg="zeroconf server listening on port 44659" Sep 02 18:51:46 volumiunten go-librespot[20563]: time="2025-09-02T18:51:46+02:00" level=debug msg="obtained new client token: AABVO+1TTeM8++nqf3orF7fKRWtYTvdlSFVj1zQi+Y4qxaV6AQBu/84nOATkvhd+sgNl+fP+Yui4KDlW+ajE3InNCafLfpS5sLwv1FqsquWYhrXz+E4wOdwEUQ6Mqdx3uN3GqWhbWIQAxOIhcn0WNIgIMsxCqY4nF+2mYUW4ndYJbXy+7EwWLvd0JGx/edWstNmB+9pRAGs63JmJhjDZ8gll2lxFsgQYhKYqmgBQKm9Q90X0iiNVOaI=" Sep 02 18:51:46 volumiunten go-librespot[20563]: time="2025-09-02T18:51:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:46 volumiunten go-librespot[20563]: time="2025-09-02T18:51:46+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:46 volumiunten go-librespot[20563]: time="2025-09-02T18:51:46+02:00" level=debug msg="completed challenge" Sep 02 18:51:46 volumiunten go-librespot[20563]: time="2025-09-02T18:51:46+02: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 " Sep 02 18:51:46 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:46 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:46 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:46 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:49 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:49 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351028. Sep 02 18:51:49 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:49 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:49 volumiunten go-librespot[20571]: go-librespot daemon starting... Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="app state loaded" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=info msg="zeroconf server listening on port 36961" Sep 02 18:51:49 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="new websocket client" Sep 02 18:51:49 volumiunten volumio[670]: info: Connection to go-librespot Websocket established Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="obtained new client token: AACIWZ5qvF/rF5ZH2ljTQH3HxyxLsUkeapjbswYV1F8/AcjR1duPdSh8RkmjKlho6zXHf7/Y1n/aS53R+/S9BR8C7UKyA2EH7S97qjHGBwehDzW/YTzcZUAPCLKViOs4vSLqETILWF8OG3XCauQDMx5NjkdmbZF5ithiCGMbfDy+7/57URVtDk+7GivfwtfoexlfUF8OPXhvCwdGRVNCPLh3m/HNtambBZQR8MP04sogSh8hMjKzyqM=" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02:00" level=debug msg="completed challenge" Sep 02 18:51:49 volumiunten go-librespot[20571]: time="2025-09-02T18:51:49+02: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 " Sep 02 18:51:49 volumiunten volumio[670]: info: Connection to go-librespot Websocket closed Sep 02 18:51:49 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:49 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:52 volumiunten volumio[670]: info: Getting Spotify volume Sep 02 18:51:52 volumiunten volumio[670]: (node:670) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:52 volumiunten volumio[670]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 02 18:51:52 volumiunten volumio[670]: (node:670) 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: 46228) Sep 02 18:51:52 volumiunten volumio[670]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Sep 02 18:51:52 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:51:52 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:51:52 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:52 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:53 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:53 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351029. Sep 02 18:51:53 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:53 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:53 volumiunten go-librespot[20593]: go-librespot daemon starting... Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="app state loaded" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=info msg="zeroconf server listening on port 42339" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="obtained new client token: AAAGwAE/PHtIQ0YAxs55BBWs180q7MqqitBiKyMS90rKahe1PFZFFqEMl1JfDucyEPVt3CkMNhW7xWnNzKn+9VwN3tuKKRY1We5owzbDFujzjmlSOE4+8ZN+X9Rl7/XIc2gix1+xMVMyC+8s2CmHjB9lYX/+K5KsFH/hrQmTFOpmYyD10O+YobmtnNk7i6ECnKDdAIRbOo1BhyqU2V+6UbP9PdAf8XAsvHT2uRUKsFVEvCfvGxPqmfM=" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02:00" level=debug msg="completed challenge" Sep 02 18:51:53 volumiunten go-librespot[20593]: time="2025-09-02T18:51:53+02: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 " Sep 02 18:51:53 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:53 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:54 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 18:51:54 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 18:51:54 volumiunten volumio[670]: info: Discovery: Getting this device information Sep 02 18:51:54 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:51:54 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 18:51:55 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:55 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:51:56 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:51:56 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351030. Sep 02 18:51:56 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:51:56 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:51:56 volumiunten go-librespot[20602]: go-librespot daemon starting... Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="app state loaded" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="stored credentials not found" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=info msg="zeroconf server listening on port 42675" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="obtained new client token: AAAzzg4+CgOgxznVV4lkdPdeug/oQb59L+MXcYetu2zZiyDKdxyA5EWiHwYKWGsBhoVkeNm5djLyXJDt9GRz6BL9b/D9rVc3orbckXAPT7zHF1PCCB8gwIoc8oMh6Whki8I7lBL5MfUf+7Vl/vNinnoYuOcOPUTyBiu757EMbnuNipKL63R5NRkRoXsGIQXgsiyLVlXYpBVG9FsnFaCZ9MSwbOdY4ED6fU7iZDXj5/MjcPMEhMhG9wM=" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="completed keyexchange" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02:00" level=debug msg="completed challenge" Sep 02 18:51:57 volumiunten go-librespot[20602]: time="2025-09-02T18:51:57+02: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 " Sep 02 18:51:57 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:51:57 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:51:58 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:51:58 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:52:00 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:52:00 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351031. Sep 02 18:52:00 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:52:00 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:52:00 volumiunten go-librespot[20613]: go-librespot daemon starting... Sep 02 18:52:00 volumiunten go-librespot[20613]: time="2025-09-02T18:52:00+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:52:00 volumiunten go-librespot[20613]: time="2025-09-02T18:52:00+02:00" level=debug msg="app state loaded" Sep 02 18:52:00 volumiunten go-librespot[20613]: time="2025-09-02T18:52:00+02:00" level=debug msg="stored credentials not found" Sep 02 18:52:00 volumiunten go-librespot[20613]: time="2025-09-02T18:52:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=info msg="zeroconf server listening on port 45985" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="obtained new client token: AAAIj0q2NwgMW3o+zgrNHPFMAkx32L3Kq3RJNKUmEDj6sigMpkHSR5WeaIaDOSwo2lcBpixXeKWzcxppNvXvwYtLmSmwU9kd0/XdJthkNuObl6ED/HwfuN+CaniFoSozmCIWZZClSJ9wcNGrEMuzulak4EwseOmtk8mk8a/UgzcJBEhArSwwx+FC7JFe2fSK3VPfbSLiILX36IKS8CFpPxTiqvcQaW9/xPpXbiRaml2LrYVYq84q" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="completed keyexchange" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02:00" level=debug msg="completed challenge" Sep 02 18:52:01 volumiunten go-librespot[20613]: time="2025-09-02T18:52:01+02: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 " Sep 02 18:52:01 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:52:01 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:52:01 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:52:01 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:52:04 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:52:04 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351032. Sep 02 18:52:04 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:52:04 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:52:04 volumiunten go-librespot[20635]: go-librespot daemon starting... Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=debug msg="app state loaded" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=debug msg="stored credentials not found" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=info msg="zeroconf server listening on port 39065" Sep 02 18:52:04 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:52:04 volumiunten go-librespot[20635]: time="2025-09-02T18:52:04+02:00" level=debug msg="new websocket client" Sep 02 18:52:04 volumiunten volumio[670]: info: Connection to go-librespot Websocket established Sep 02 18:52:05 volumiunten go-librespot[20635]: time="2025-09-02T18:52:05+02:00" level=debug msg="obtained new client token: AAC/lwSAIfxgyFBAvwGouVhtpjsJjvC7atkrcvXmmWVAlTK0tk07IGYanCxfEZ2OiOBIWdhPngnSvHhtSqw8BYJiXAMX4nE/mQ337YLjXsdWQnqb/D+fN/b0ylydKIZpngAw9WZGiLyNgE3TkgW5D3N1yzFhTywBs4FpzMW8DD4UBtqXMNjoNkDMRkUXjwrJk+Mq3vdtbnGqHqEY7lUpxSXHQqEg7LHEe27Z1oUhDZ3oDRTR1YNJZ3I=" Sep 02 18:52:05 volumiunten go-librespot[20635]: time="2025-09-02T18:52:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:52:05 volumiunten go-librespot[20635]: time="2025-09-02T18:52:05+02:00" level=debug msg="completed keyexchange" Sep 02 18:52:05 volumiunten go-librespot[20635]: time="2025-09-02T18:52:05+02:00" level=debug msg="completed challenge" Sep 02 18:52:05 volumiunten go-librespot[20635]: time="2025-09-02T18:52:05+02: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 " Sep 02 18:52:05 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:52:05 volumiunten volumio[670]: info: Connection to go-librespot Websocket closed Sep 02 18:52:05 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:52:07 volumiunten sudo[20644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 02 18:52:07 volumiunten sudo[20644]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 02 18:52:07 volumiunten sudo[20644]: pam_unix(sudo:session): session closed for user root Sep 02 18:52:07 volumiunten sudo[20646]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 02 18:52:07 volumiunten sudo[20646]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 02 18:52:07 volumiunten sudo[20646]: pam_unix(sudo:session): session closed for user root Sep 02 18:52:07 volumiunten volumio[670]: verbose: New Socket.io Connection to 192.168.1.38 from 192.168.1.86 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetVisibleSources Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 02 18:52:07 volumiunten volumio[670]: info: Received Get System Info Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 18:52:07 volumiunten volumio[670]: info: Discovery: Getting this device information Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:52:07 volumiunten volumio[670]: info: Listing playlists Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 02 18:52:07 volumiunten volumio[670]: info: Getting Spotify volume Sep 02 18:52:07 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 02 18:52:07 volumiunten volumio[670]: (node:670) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:52:07 volumiunten volumio[670]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Sep 02 18:52:07 volumiunten volumio[670]: (node:670) 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: 46229) Sep 02 18:52:07 volumiunten volumio[670]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Sep 02 18:52:08 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:52:08 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:52:08 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:52:08 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:52:08 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:52:08 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351033. Sep 02 18:52:08 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:52:08 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:52:08 volumiunten go-librespot[20652]: go-librespot daemon starting... Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="app state loaded" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="stored credentials not found" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=info msg="zeroconf server listening on port 39547" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="obtained new client token: AAAgb7irk9Mxw0KFBy5xjgJCRs9fvN5qYyz+a6sfxk1QcUoKHLJpU/ciky4eNWXwLHkO0mNzTklfjvp0Yqu8BgNHN6RaF88MDBtkHlWVsmOBSVonPCeQmiCxop5Xp/gJKo15XM774I57XCbMui1JMgKaEYW9o8nlWWiDU0hSQjddWGzMAYCAlj7NcXux21re5AihYHoFy1Xy3flIfCTojp5/q7qsbHmLtPoe2ss1+j6uOkniFXk/spI=" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="completed keyexchange" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02:00" level=debug msg="completed challenge" Sep 02 18:52:08 volumiunten go-librespot[20652]: time="2025-09-02T18:52:08+02: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 " Sep 02 18:52:08 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:52:08 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:52:09 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 02 18:52:09 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 02 18:52:09 volumiunten volumio[670]: info: Received Get System Info Sep 02 18:52:09 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 18:52:09 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 18:52:09 volumiunten volumio[670]: info: Discovery: Getting this device information Sep 02 18:52:09 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:52:09 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 02 18:52:10 volumiunten volumio[670]: info: Received Get System Info Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 02 18:52:10 volumiunten volumio[670]: info: Discovery: Getting this device information Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::volumioGetState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::volumioStop Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::stop Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::stPlaybackTimer Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::updateTrackBlock Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrackBlock Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::serviceStop Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::serviceStop Sep 02 18:52:10 volumiunten volumio[670]: info: [1756831930888] ControllerWebradio::stop Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand stop Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] CurState: stop PrevState: play Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 02 18:52:10 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:52:10 volumiunten volumio[670]: info: Sep 02 18:52:10 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand stop took 16 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand status took 1 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:52:10 volumiunten volumio[670]: info: Sep 02 18:52:10 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:52:10 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:52:10 volumiunten volumio[670]: info: Sep 02 18:52:10 volumiunten volumio[670]: ---------------------------- MPD announces state update: player Sep 02 18:52:10 volumiunten volumio[670]: info: ControllerMpd::getState Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand status Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand status took 4 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand status took 2 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::parseState Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 02 18:52:10 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Sep 02 18:52:10 volumiunten volumio[670]: info: ------------------------------ 28ms Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 15 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: info: sendMpdCommand playlistinfo took 15 milliseconds Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:52:10 volumiunten volumio[670]: verbose: ControllerMpd::parseTrackInfo Sep 02 18:52:10 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Sep 02 18:52:10 volumiunten volumio[670]: info: ControllerMpd::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::servicePushState Sep 02 18:52:10 volumiunten volumio[670]: info: CoreStateMachine::pushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: CoreCommandRouter::volumioPushState Sep 02 18:52:10 volumiunten volumio[670]: info: CorePlayQueue::getTrack 0 Sep 02 18:52:10 volumiunten volumio[670]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Sep 02 18:52:10 volumiunten volumio[670]: info: ------------------------------ 44ms Sep 02 18:52:10 volumiunten volumio[670]: info: ------------------------------ 42ms Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] CurState: stop PrevState: play Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] CurState: stop PrevState: play Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] CurState: stop PrevState: play Sep 02 18:52:10 volumiunten volumio[670]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 02 18:52:10 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:52:10 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:52:10 volumiunten volumio[670]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Sep 02 18:52:11 volumiunten volumio[670]: info: Initializing connection to go-librespot Websocket Sep 02 18:52:11 volumiunten volumio[670]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 02 18:52:11 volumiunten volumio[670]: info: [ASDebug] Togle GPIO: OFF Sep 02 18:52:11 volumiunten volumio[670]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 02 18:52:11 volumiunten volumio[670]: Error: ESPIPE: invalid seek, write Sep 02 18:52:11 volumiunten volumio[670]: at Object.writeSync (fs.js:711:3) Sep 02 18:52:11 volumiunten volumio[670]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Sep 02 18:52:11 volumiunten volumio[670]: at AmpSwitchController.off (/data/plugins/system_controller/ampswitch/index.js:221:23) Sep 02 18:52:11 volumiunten volumio[670]: at Timeout._onTimeout (/data/plugins/system_controller/ampswitch/index.js:195:88) Sep 02 18:52:11 volumiunten volumio[670]: at listOnTimeout (internal/timers.js:554:17) Sep 02 18:52:11 volumiunten volumio[670]: at processTimers (internal/timers.js:497:7) { Sep 02 18:52:11 volumiunten volumio[670]: errno: -29, Sep 02 18:52:11 volumiunten volumio[670]: syscall: 'write', Sep 02 18:52:11 volumiunten volumio[670]: code: 'ESPIPE' Sep 02 18:52:11 volumiunten volumio[670]: } Sep 02 18:52:11 volumiunten volumio[670]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 02 18:52:11 volumiunten systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 02 18:52:11 volumiunten systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 351034. Sep 02 18:52:11 volumiunten systemd[1]: Stopped go-librespot Daemon. Sep 02 18:52:12 volumiunten systemd[1]: Started go-librespot Daemon. Sep 02 18:52:12 volumiunten go-librespot[20669]: go-librespot daemon starting... Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=info msg="running go-librespot 0.3.2" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="app state loaded" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="stored credentials not found" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=info msg="zeroconf server listening on port 39043" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="obtained new client token: AADzHlLX+2FpVsqD71ugafSvbvuPWaZDLqMa7JVRU+bCs8HIn14DuSbSgsEH7spQUBlA8Ot+WJSnR8pQCJtW7Lu0bAIC4+EP6nqsSg6jlrKGZGGuxBYtJY4B6/lXZ4vOIgClL6P81jA9EaDoC8vap9YvCu2ls2KzYNE7K6rib9gLBrvaCqT5wc8Dk9p8rT8prBo602ssZRTAwmcflKV5mUTtE4eYvptAIk1m435hPNw9sQQt8l9qSwM=" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="completed keyexchange" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02:00" level=debug msg="completed challenge" Sep 02 18:52:12 volumiunten go-librespot[20669]: time="2025-09-02T18:52:12+02: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 " Sep 02 18:52:12 volumiunten systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 02 18:52:12 volumiunten systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 02 18:52:12 volumiunten sudo[20692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-02 18:51 Sep 02 18:52:12 volumiunten sudo[20692]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"