-- Logs begin at Sun 2025-08-31 08:54:05 CEST, end at Sun 2025-08-31 11:00:58 CEST. -- Aug 31 10:59:00 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:00 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189951. Aug 31 10:59:03 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:03 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:03 volumio go-librespot[23293]: go-librespot daemon starting... Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=debug msg="app state loaded" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+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]" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+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]" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+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]" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=info msg="zeroconf server listening on port 40207" Aug 31 10:59:03 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=debug msg="new websocket client" Aug 31 10:59:03 volumio volumio[1054]: info: Connection to go-librespot Websocket established Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=debug msg="obtained new client token: AAAVoG/30MGFkNDYRqGadgx/K18BwhhbDmekQ/4fR7qtQxvDg3noMxaq1ueET2SHmHXb9KECXRKotK/LX3Yqtst0dxFSkIiM+YrBV40ZITP8NU/rB8fng4sDY+arVop8+UZESYTbpgG+c7dzd78Cl+8GQHFXNZTfkoyjiqd4PegyjV1bNo+R6xiD2qjUOZi6a8Ww2Y97fhL04rujQCjeCA4GU7hTNpXbidHaHu7314YpZ+RpUduB4ze9" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=debug msg="completed challenge" Aug 31 10:59:03 volumio go-librespot[23293]: time="2025-08-31T10:59:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:03 volumio volumio[1054]: info: Connection to go-librespot Websocket closed Aug 31 10:59:06 volumio volumio[1054]: info: Getting Spotify volume Aug 31 10:59:06 volumio volumio[1054]: (node:1054) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:06 volumio volumio[1054]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 31 10:59:06 volumio volumio[1054]: (node:1054) 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: 21873) Aug 31 10:59:06 volumio volumio[1054]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 31 10:59:06 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:06 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 10:59:06 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:06 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189952. Aug 31 10:59:06 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:06 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:06 volumio go-librespot[23302]: go-librespot daemon starting... Aug 31 10:59:06 volumio go-librespot[23302]: time="2025-08-31T10:59:06+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:06 volumio go-librespot[23302]: time="2025-08-31T10:59:06+02:00" level=debug msg="app state loaded" Aug 31 10:59:06 volumio go-librespot[23302]: time="2025-08-31T10:59:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+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]" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+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]" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+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]" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+02:00" level=info msg="zeroconf server listening on port 39377" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+02:00" level=debug msg="obtained new client token: AADErGReca0yyDt8DLBA2u8Gf/sdfoodVNqiIx41UR2nRncNrUYxKmNI0pq/9OMeGF0zCuQ44aP1GNcwPKvpPS6FfeELYdPI69FTR2pLhzPiDAb1SoYCekRS66xEkjU4iqtcETbdYdR24fKgwUPkwi0QjWLzqFv5lyYI49ByJJscR2dFk1UbbkRf+9KXMeBBjIrE002xtZZ7/g0AL5sakHkis/bOkNMIKVTmJW68IJ6C0EIXIVtHlw==" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+02:00" level=debug msg="completed challenge" Aug 31 10:59:07 volumio go-librespot[23302]: time="2025-08-31T10:59:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:09 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:09 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189953. Aug 31 10:59:10 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:10 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:10 volumio go-librespot[23310]: go-librespot daemon starting... Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=debug msg="app state loaded" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+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]" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+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]" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+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]" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=info msg="zeroconf server listening on port 37325" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=debug msg="obtained new client token: AADMy0BfQQAqVBUPbpbYKmlR2I03mrYwcU6023Jkj1J9oH5sd2a5pCRqM/79kcyV3TBM31cV6wb/Uu8b1Zwd7L8ERC8cuD5z5b5qfmsiqq8mLPa0E72fXOrOUJ38w770hpVD6QFKssEEtzLRu/brC4CtjdHfAvNuAiHrQq6e1e2nsEV31/CZm5hOrB08OzGFx7CHE8kNw/Yau9PorZsgsjEXXYMAnTDrAQDhDeI2lz+xP1cADChwWlzk" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=debug msg="completed challenge" Aug 31 10:59:10 volumio go-librespot[23310]: time="2025-08-31T10:59:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:12 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:12 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189954. Aug 31 10:59:14 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:14 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:14 volumio go-librespot[23332]: go-librespot daemon starting... Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=debug msg="app state loaded" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+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]" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+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]" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+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]" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=info msg="zeroconf server listening on port 44787" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=debug msg="obtained new client token: AABwIqO6jDECPUalzzPqnVSy8ddDe00kOgVpTVRjbdoszo8bpxAg/UzPz7IiiTFf4i8XR0PXN+P9mov5xxCRH3mPl/gNpCZ7efOTtsYSs+okwfW3xn33Ggb+6W71lpBoDpbIWgiri0lIhTKHrYX/2/6dxsQEJmErZWK3Kx+QvaB34YjcrG6Oqezot6gD2+OdCOMwp01bfdDXIpo378dePNWNwXU5y7/d/pIltIu63G+DwkQFYnTvhMi7" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=debug msg="completed challenge" Aug 31 10:59:14 volumio go-librespot[23332]: time="2025-08-31T10:59:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:15 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:15 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189955. Aug 31 10:59:17 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:17 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:17 volumio go-librespot[23340]: go-librespot daemon starting... Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+02:00" level=debug msg="app state loaded" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+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]" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+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]" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+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]" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+02:00" level=info msg="zeroconf server listening on port 35023" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+02:00" level=debug msg="obtained new client token: AABrKMCCmLaKLeuNfCvTJO5z6fFaRZoXZS7Mo5IMt0Wsg31GUnZ3pyhzZFmGKMx8dRHwjGWzM9ODe9FeGIhxuYAkZ4FJkNRZNC88jsP6Mt6fOFH0yfrF2U4yGXhytHxcEVkADT8SdK3VBID7ZdJDEY4ANeA6stuk8Z0b8asl/GRO18MbgM5Wh/TiNymnVISvnyugF7QTZ1bT4AEm9VOkH0BDRwRSutsG/noQ1GBw/afUOQ9DvwM65w9n" Aug 31 10:59:17 volumio go-librespot[23340]: time="2025-08-31T10:59:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:18 volumio go-librespot[23340]: time="2025-08-31T10:59:18+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:18 volumio go-librespot[23340]: time="2025-08-31T10:59:18+02:00" level=debug msg="completed challenge" Aug 31 10:59:18 volumio go-librespot[23340]: time="2025-08-31T10:59:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:18 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:18 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189956. Aug 31 10:59:21 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:21 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:21 volumio go-librespot[23348]: go-librespot daemon starting... Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=debug msg="app state loaded" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:21 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=debug msg="new websocket client" Aug 31 10:59:21 volumio volumio[1054]: info: Connection to go-librespot Websocket established Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+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]" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+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]" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+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]" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=info msg="zeroconf server listening on port 37955" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=debug msg="obtained new client token: AADWOAyAjxFZ/+gilwrpdf4mrUQZuBHID+9Kdil2FT+apLRcJThZ6dYpuKVNXHqpuTGJW1FtBBn/JLxw+LDqeU97Z4BVfx63ikpVPouvkV1QLpUw559LA2fAZznz6YNdZ1PCYRG3OrD6kSGW76PqF4BxleS4nkuSdoBOSGfIzKtLQ2oIZeXjwU8Yd/SMR0dt71l4pMvH6cT/gPW9FVWMxklkBwgeKWup/s6bSBSa+hX1JvqbNwU/400v" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=debug msg="completed challenge" Aug 31 10:59:21 volumio go-librespot[23348]: time="2025-08-31T10:59:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:21 volumio volumio[1054]: info: Connection to go-librespot Websocket closed Aug 31 10:59:24 volumio volumio[1054]: info: Getting Spotify volume Aug 31 10:59:24 volumio volumio[1054]: (node:1054) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:24 volumio volumio[1054]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 31 10:59:24 volumio volumio[1054]: (node:1054) 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: 21874) Aug 31 10:59:24 volumio volumio[1054]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 31 10:59:24 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:24 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 10:59:24 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:24 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189957. Aug 31 10:59:25 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:25 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:25 volumio go-librespot[23414]: go-librespot daemon starting... Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=debug msg="app state loaded" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+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]" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+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]" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+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]" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=info msg="zeroconf server listening on port 35519" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=debug msg="obtained new client token: AAA4MhJNL+gsQ4aDZowOkvQa2SRKrua3roPHHgZnyZI868KsnZywo5k0QkQK0UIboTv7KW9zRHF3ltLyDWdzEap8XbcprhTDKdwgA1Bau3F+VLJXKp+zmgGVBwz5MTpcfQ+AvoLLEGTKh+rxd6+oRno0ds7ZvWKNXWaxwxOA/Iw+KG97vtnVta4boAiZrdCEOnLA7QwxiARYbuQsC6dldgYTD30MHtDxDtezBhY24kjZHfVTpOZ1twrb" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=debug msg="completed challenge" Aug 31 10:59:25 volumio go-librespot[23414]: time="2025-08-31T10:59:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:27 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:27 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189958. Aug 31 10:59:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:28 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:28 volumio go-librespot[23422]: go-librespot daemon starting... Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+02:00" level=debug msg="app state loaded" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+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]" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+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]" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+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]" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+02:00" level=info msg="zeroconf server listening on port 33799" Aug 31 10:59:28 volumio go-librespot[23422]: time="2025-08-31T10:59:28+02:00" level=debug msg="obtained new client token: AAAaC0uXF5jMexL32piAN7WNkyXaqs9szLd6uzlOU76IbhAEqsrUBI1f1NZy9gi/VnXKzI06jbouIG58MlSYjubQOwGyO1tZO9uuq4nMp8fTfcS19A502gNTQzXpecezWcir67ipI9+tubEb4EHMImHG6OVG228mRqF2t9FKq2pEBuVz40NBATqjxlo8iMjlqs5ZfjtQKKy/7mTOapHFD0k9c7BLuep2V/83moiErLZmXRtSCheGNWeT" Aug 31 10:59:29 volumio go-librespot[23422]: time="2025-08-31T10:59:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:29 volumio go-librespot[23422]: time="2025-08-31T10:59:29+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:29 volumio go-librespot[23422]: time="2025-08-31T10:59:29+02:00" level=debug msg="completed challenge" Aug 31 10:59:29 volumio go-librespot[23422]: time="2025-08-31T10:59:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:30 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:30 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189959. Aug 31 10:59:32 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:32 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:32 volumio go-librespot[23444]: go-librespot daemon starting... Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=debug msg="app state loaded" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+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]" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+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]" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+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]" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=info msg="zeroconf server listening on port 41317" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=debug msg="obtained new client token: AAC3g1BG80iYZY/oqLCu04KLCmX/AxHhGVQ2v3pPBrqcqrT5jhnFesk1o2sAal1y0G5Kz+gwIpJRVHHrgGUpyy5vNPHZe0M39mLUJFNYB+iA7jOKlzpnVsl3jlmwX5un6+e9oUrbvKr26t/JnuQ5DhiRyKsfxmEXNfm+vULTwr7Vyk/sUuoj/crfxWQwB2xjo9cRlXip32NbBrpqka73Ke6gsYPbK8eN+XKF8fn3SEA+9qKwBg/ilazZ" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=debug msg="completed challenge" Aug 31 10:59:32 volumio go-librespot[23444]: time="2025-08-31T10:59:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:33 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:33 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189960. Aug 31 10:59:36 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:36 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:36 volumio go-librespot[23453]: go-librespot daemon starting... Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=debug msg="app state loaded" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+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]" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+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]" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+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]" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=info msg="zeroconf server listening on port 39853" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=debug msg="obtained new client token: AADTaf8wRmb1RYIVMtRvcoCnq8oH5zng0I/YPWzbX/IC70JXgEcMssboOrkx4/v71RCvVo2Z63F+BWiKN1gJAnBjHjUIJnVQnHbdcNuLEf09gWw+M0fzleSlgs3Qp75K1mGgw/qpavJU2C56RO7//8QgK0UemxZa7jPZ9A0MYfoJ8dBWhIMsVof99/56mennct0cZmWmO+dobQXefWQ8QeqWg1+fJC8JbDAZI9G2j7cjO28xzHrn/+mh" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=debug msg="completed challenge" Aug 31 10:59:36 volumio go-librespot[23453]: time="2025-08-31T10:59:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:36 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:36 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189961. Aug 31 10:59:39 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:39 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:39 volumio go-librespot[23461]: go-librespot daemon starting... Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+02:00" level=debug msg="app state loaded" Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:39 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+02:00" level=debug msg="new websocket client" Aug 31 10:59:39 volumio volumio[1054]: info: Connection to go-librespot Websocket established Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+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]" Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+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]" Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+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]" Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+02:00" level=info msg="zeroconf server listening on port 33229" Aug 31 10:59:39 volumio go-librespot[23461]: time="2025-08-31T10:59:39+02:00" level=debug msg="obtained new client token: AAD/0MOSrTqTwz8EjjCobgVSFGrQGDUvOKkTdpd8YO69B1DvKL5NZq0bqpPrVZ8Gt60Id2h5DY+mNtKroMUNuHZmbvU0ktOYh43VjEBnUWzFeUo4VS/Ih+al2dSIGTWH88oDjK8MjVmWAABXjYTA7Exdx0fD0Uuy5bS9VPFujxA0CT6lUJ0D0wsMsAAwFnINOSB0WQsfILPq4X/8SrlmEPDkywZBHh/upcrUFbloY5zTrSZtj5xWG/Ir" Aug 31 10:59:40 volumio go-librespot[23461]: time="2025-08-31T10:59:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:40 volumio go-librespot[23461]: time="2025-08-31T10:59:40+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:40 volumio go-librespot[23461]: time="2025-08-31T10:59:40+02:00" level=debug msg="completed challenge" Aug 31 10:59:40 volumio go-librespot[23461]: time="2025-08-31T10:59:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:40 volumio volumio[1054]: info: Connection to go-librespot Websocket closed Aug 31 10:59:41 volumio sudo[23470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 10:59:41 volumio sudo[23470]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 10:59:41 volumio sudo[23470]: pam_unix(sudo:session): session closed for user root Aug 31 10:59:41 volumio sudo[23473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 10:59:41 volumio sudo[23473]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 10:59:41 volumio sudo[23473]: pam_unix(sudo:session): session closed for user root Aug 31 10:59:41 volumio volumio[1054]: verbose: New Socket.io Connection to 192.168.1.60 from 192.168.1.196 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 31 10:59:41 volumio volumio[1054]: info: Received Get System Info Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 10:59:41 volumio volumio[1054]: info: Discovery: Getting this device information Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:41 volumio volumio[1054]: info: Listing playlists Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 10:59:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:42 volumio volumio[1054]: info: Getting Spotify volume Aug 31 10:59:42 volumio volumio[1054]: (node:1054) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:42 volumio volumio[1054]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 31 10:59:42 volumio volumio[1054]: (node:1054) 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: 21875) Aug 31 10:59:42 volumio volumio[1054]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:42 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 10:59:42 volumio volumio[1054]: info: Received Get System Info Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 10:59:42 volumio volumio[1054]: info: Discovery: Getting this device information Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 10:59:42 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 31 10:59:43 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:43 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189962. Aug 31 10:59:43 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:43 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:43 volumio go-librespot[23492]: go-librespot daemon starting... Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=debug msg="app state loaded" Aug 31 10:59:43 volumio volumio[1054]: info: CoreCommandRouter::volumioGetQueue Aug 31 10:59:43 volumio volumio[1054]: info: CoreStateMachine::getQueue Aug 31 10:59:43 volumio volumio[1054]: info: CorePlayQueue::getQueue Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+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]" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+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]" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+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]" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=info msg="zeroconf server listening on port 37315" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=debug msg="obtained new client token: AACcEwdeejKif6vrIB4FQvflL+KRCMgDRWmCS16HX+sAobBs/fD8QQxQgb/mkF5EU7wtSF9xgpRTSnXHtj72/q+yc2YKwb/ht7ZGFFOxXNZVNWi2TRX24bAXy4w+HEjYinANk+RJ6fmpteVxrRlf0/FUikDM5kPIiLC/ig9n9tusnhe0bG/2ogUOVtX3BzQ4dgXlzrYCRWAs0XmIcLEZ6YZYu3+7ZhqYYG+5lwfrOLkmkM6a+dMXu24R" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=debug msg="completed challenge" Aug 31 10:59:43 volumio go-librespot[23492]: time="2025-08-31T10:59:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:46 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:46 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:46 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 10:59:46 volumio volumio[1054]: info: Received Get System Info Aug 31 10:59:46 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 10:59:46 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 10:59:46 volumio volumio[1054]: info: Discovery: Getting this device information Aug 31 10:59:46 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:46 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 10:59:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189963. Aug 31 10:59:47 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:47 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:47 volumio go-librespot[23500]: go-librespot daemon starting... Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=debug msg="app state loaded" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:47 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+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]" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+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]" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+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]" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=info msg="zeroconf server listening on port 32909" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=debug msg="obtained new client token: AAA18eVHnL7A5ih6eIf8bcynOjsUg/qyDIidj95ani/toiAoniDe3ZDS5cEf2GivyYOzMqSHnJ3sCRepzBhhMHFwvzw4NmObgGz6f/gkN31FyC4fijrNkk01YdPEmi5PANidXq/i8O0yPTv8zEMFJhuWZSThqCY6eZ+9wkSnnxYaKilDI9i4wzewjDf8bBpKIR4HtLsogWI3Vq8tvWE9q3o6dY6epqPzqkf/1p+6ce7+1JvZugCVUQTc" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=debug msg="completed challenge" Aug 31 10:59:47 volumio go-librespot[23500]: time="2025-08-31T10:59:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:49 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:49 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 10:59:49 volumio volumio[1054]: info: Retrieving Cloud Streaming UI Aug 31 10:59:49 volumio volumio[1054]: info: Getting Tidal Cloud Configuration Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 10:59:49 volumio volumio[1054]: info: Getting Qobuz Cloud Configuration Aug 31 10:59:49 volumio volumio[1054]: info: Asking plugin for UI Config Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 10:59:49 volumio volumio[1054]: info: Getting Spotify Cloud Configuration Aug 31 10:59:49 volumio volumio[1054]: info: Asking plugin for UI Config Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 10:59:49 volumio volumio[1054]: info: Saving Spotify Acccount Aug 31 10:59:49 volumio volumio[1054]: info: Got it Aug 31 10:59:49 volumio volumio[1054]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Aug 31 10:59:49 volumio volumio[1054]: info: Got Tidal Cloud Configuration Aug 31 10:59:49 volumio volumio[1054]: info: Got it Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 10:59:49 volumio volumio[1054]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 10:59:49 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 31 10:59:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189964. Aug 31 10:59:50 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:50 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:50 volumio go-librespot[23513]: go-librespot daemon starting... Aug 31 10:59:50 volumio go-librespot[23513]: time="2025-08-31T10:59:50+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:50 volumio go-librespot[23513]: time="2025-08-31T10:59:50+02:00" level=debug msg="app state loaded" Aug 31 10:59:50 volumio go-librespot[23513]: time="2025-08-31T10:59:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+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]" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+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]" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+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]" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+02:00" level=info msg="zeroconf server listening on port 38807" Aug 31 10:59:51 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+02:00" level=debug msg="obtained new client token: AAAgRT8cRctgP33jN41qwJrpAz3OnvJL7JRYAFigOg4p94VzBc47Scfiwf8VV6lPKyE406mnO9Q4CNEYGXZ2OoM2EQ6jVsUAOlaJ916BZeMbBlwGcK0f1WOsaU5jrfdr9/Is8FX00gWPZ4s8lY92nnxLmA6EhOkQTLGtAp6Zq1AchNLiHS6ihkKwnOaDwwtziAtITiBN8Gl4jeC/xVxvlcM5gzxbrbcdEOpTRTg859tjdlz0ifma0g==" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+02:00" level=debug msg="completed challenge" Aug 31 10:59:51 volumio go-librespot[23513]: time="2025-08-31T10:59:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:52 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:52 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:53 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 10:59:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189965. Aug 31 10:59:54 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:54 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:54 volumio go-librespot[23536]: go-librespot daemon starting... Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+02:00" level=debug msg="app state loaded" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+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]" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+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]" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+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]" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+02:00" level=info msg="zeroconf server listening on port 37831" Aug 31 10:59:54 volumio go-librespot[23536]: time="2025-08-31T10:59:54+02:00" level=debug msg="obtained new client token: AAAu2SuStzr2WMd7EKy6XHBwIslRGfO97vuOfm3jlJsmbjNPBJ5oEVfSVaiPErkzOBYpZIMXHThMjkvVbS7PvCDOG3UZPnB/DzJnL0KFA3mposnt83iIBclS+Q1NPGP9X+F5K5e4WK6a2CY3vvNjrcxIMMTed/FHfqOEfPYwujET4GJqlfZk8vw/fUsq/so080hW+KuGcAIXBSfMd7Tj+pkVPmbFLuKNm9CPAmo4DC+AW7jrOCh9AbV1" Aug 31 10:59:55 volumio go-librespot[23536]: time="2025-08-31T10:59:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:55 volumio go-librespot[23536]: time="2025-08-31T10:59:55+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:55 volumio go-librespot[23536]: time="2025-08-31T10:59:55+02:00" level=debug msg="completed challenge" Aug 31 10:59:55 volumio go-librespot[23536]: time="2025-08-31T10:59:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 10:59:55 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 10:59:55 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 10:59:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Aug 31 10:59:56 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand update Aug 31 10:59:56 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 10:59:56 volumio volumio[1054]: info: Aug 31 10:59:56 volumio volumio[1054]: ---------------------------- MPD announces state update: update Aug 31 10:59:56 volumio volumio[1054]: info: sendMpdCommand update took 8 milliseconds Aug 31 10:59:56 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 10:59:56 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 10:59:56 volumio volumio[1054]: info: sendMpdCommand status took 6 milliseconds Aug 31 10:59:56 volumio volumio[1054]: info: sendMpdCommand status took 3 milliseconds Aug 31 10:59:56 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 10:59:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 10:59:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189966. Aug 31 10:59:58 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 10:59:58 volumio systemd[1]: Started go-librespot Daemon. Aug 31 10:59:58 volumio go-librespot[23547]: go-librespot daemon starting... Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=debug msg="app state loaded" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+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]" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+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]" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+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]" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=info msg="zeroconf server listening on port 36593" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=debug msg="obtained new client token: AABBlvZ+2lf9aso2XGLNJe08m7zA38lFrVTEyAXTytqVxs9gLc3gwu0+sAsHqTmBGmTOlvbwCPcYcnOsHHHT79JVR/5725ynEn1IBu2U7hF5ZMWU82ZwiWbFBwH70kW/5+IK57BDJ9EVNTN4aHcWiUtjietNwGMjt9uPpSiXZPYcQYRM4UWHqwcrAGcFSze7YPDteDZyap2ihJrtQ7h0DwzsoJntge/LZszTcFNNw20PbMpwNqkjYR6y" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=debug msg="completed keyexchange" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=debug msg="completed challenge" Aug 31 10:59:58 volumio go-librespot[23547]: time="2025-08-31T10:59:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 10:59:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 10:59:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189967. Aug 31 11:00:02 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:02 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:02 volumio go-librespot[23569]: go-librespot daemon starting... Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=debug msg="app state loaded" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+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]" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+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]" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+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]" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=info msg="zeroconf server listening on port 36655" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=debug msg="obtained new client token: AADXXN9nu9DyMJPffarA2KsQ09TUYe3wywoBqLhuu1Qr79Rz6GSSd5vTjyoNt1s1LlomnSmBkUSbya015TLcN4HqtBVxvcprvQsSoB9R4XkwBxZVImchbS2Sxw/wFCgTBtXAKqJaTzJ25jGpzvScLsIFmtTAoDzT4z5RDW9aSiECh/MW4E/G7XPjNkne6hVrStA7CQp2BbCAmkM6yBPUef9e8Yko36s3drVcm6UIXzDJG0jOW/UaHD4j" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=debug msg="completed challenge" Aug 31 11:00:02 volumio go-librespot[23569]: time="2025-08-31T11:00:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:03 volumio volumio[1054]: info: Command Router : Notfying DB Updatetrue Aug 31 11:00:03 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:03 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:03 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:03 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:03 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:03 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:03 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:03 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:03 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:03 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:03 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:03 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 11:00:03 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:03 volumio volumio[1054]: info: ------------------------------ 7074ms Aug 31 11:00:03 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:03 volumio volumio[1054]: info: Aug 31 11:00:03 volumio volumio[1054]: ---------------------------- MPD announces state update: update Aug 31 11:00:03 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:03 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:03 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:03 volumio volumio[1054]: info: Aug 31 11:00:03 volumio volumio[1054]: ---------------------------- MPD announces state update: update Aug 31 11:00:03 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:03 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:03 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:03 volumio volumio[1054]: info: sendMpdCommand status took 5 milliseconds Aug 31 11:00:03 volumio volumio[1054]: info: sendMpdCommand status took 4 milliseconds Aug 31 11:00:03 volumio volumio[1054]: info: sendMpdCommand status took 4 milliseconds Aug 31 11:00:03 volumio volumio[1054]: info: sendMpdCommand status took 4 milliseconds Aug 31 11:00:03 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189968. Aug 31 11:00:05 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:05 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:05 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:05 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:05 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 41 09 20 00 00 08 00 Aug 31 11:00:05 volumio kernel: critical medium error, dev sda, sector 1195444512 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 3 Aug 31 11:00:05 volumio volumio[1054]: info: Command Router : Notfying DB Updatetrue Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Aug 31 11:00:05 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:05 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:05 volumio go-librespot[23583]: go-librespot daemon starting... Aug 31 11:00:05 volumio go-librespot[23583]: time="2025-08-31T11:00:05+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:05 volumio go-librespot[23583]: time="2025-08-31T11:00:05+02:00" level=debug msg="app state loaded" Aug 31 11:00:05 volumio go-librespot[23583]: time="2025-08-31T11:00:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:05 volumio volumio[1054]: info: Command Router : Notfying DB Updatetrue Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Aug 31 11:00:05 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:05 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:05 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:05 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:05 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:05 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:05 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:05 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:05 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:05 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:05 volumio volumio[1054]: info: ------------------------------ 2825ms Aug 31 11:00:05 volumio volumio[1054]: info: ------------------------------ 2825ms Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 11:00:05 volumio volumio[1054]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 31 11:00:05 volumio volumio[1054]: info: Received Get System Version Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 11:00:05 volumio volumio[1054]: info: Received Get System Info Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 11:00:05 volumio volumio[1054]: info: Discovery: Getting this device information Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Aug 31 11:00:05 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:06 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=debug msg="new websocket client" Aug 31 11:00:06 volumio volumio[1054]: info: Connection to go-librespot Websocket established Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+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]" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+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]" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+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]" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=info msg="zeroconf server listening on port 42201" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=debug msg="obtained new client token: AABb8DmoDxY6tXdhh/CzMXq73J27mna9afXG/AUDt1IaNGi5EKylvqp8heH45TjQ4Jo0IGQ53yCsgxhK9PjH83VsrVF8T20ij+V93MBOjJSK6cnYz6igAZBhYyCUw3S63DYNtUMyVTHv8ekxlbwE02zLFka3CdQ7LfaSkj80oKCLMeVIA4WmxWNtTcDl8x9GEUwPFQZ0LMMQ0fkcOJwo8NyMFbuln82zlS9VZ7R7ggeTL4BXJBvibw==" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=debug msg="completed challenge" Aug 31 11:00:06 volumio go-librespot[23583]: time="2025-08-31T11:00:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:06 volumio volumio[1054]: info: Connection to go-librespot Websocket closed Aug 31 11:00:09 volumio volumio[1054]: info: Getting Spotify volume Aug 31 11:00:09 volumio volumio[1054]: (node:1054) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:09 volumio volumio[1054]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 31 11:00:09 volumio volumio[1054]: (node:1054) 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: 21876) Aug 31 11:00:09 volumio volumio[1054]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 31 11:00:09 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 11:00:09 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:09 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:09 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189969. Aug 31 11:00:09 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:09 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:09 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:09 volumio go-librespot[23593]: go-librespot daemon starting... Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+02:00" level=debug msg="app state loaded" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+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]" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+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]" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+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]" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+02:00" level=info msg="zeroconf server listening on port 46003" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+02:00" level=debug msg="obtained new client token: AACbkQhbiq+OptGZAyA5TkclDj3cq09LcpBy3tRVkLByUUyyO9ziUwLOldczlfzYPtXoNgstfvPUupER+EwWDXolQvdLhjDz86mWE2MMuGovLy/8apgnzIyDQsvyrP62k5xJ7CUhVGlTNGGMY2IHiBLn+EfqzqYjXC1JFVXNFJ3qlv/x92M6KILPRd8tWtAF3EgxGoeSItIyG1KNZaz5ElV1s+3eRzBKBE3J0jr6K9Mm4u5GWcjseAm6" Aug 31 11:00:09 volumio go-librespot[23593]: time="2025-08-31T11:00:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:10 volumio go-librespot[23593]: time="2025-08-31T11:00:10+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:10 volumio go-librespot[23593]: time="2025-08-31T11:00:10+02:00" level=debug msg="completed challenge" Aug 31 11:00:10 volumio go-librespot[23593]: time="2025-08-31T11:00:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:10 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=3s Aug 31 11:00:10 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:10 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:10 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 48 e0 00 00 f0 00 Aug 31 11:00:10 volumio kernel: critical medium error, dev sda, sector 1207781600 op 0x0:(READ) flags 0x84700 phys_seg 30 prio class 3 Aug 31 11:00:12 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:12 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189970. Aug 31 11:00:13 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:13 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:13 volumio go-librespot[23615]: go-librespot daemon starting... Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=debug msg="app state loaded" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+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]" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+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]" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+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]" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=info msg="zeroconf server listening on port 42963" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=debug msg="obtained new client token: AADkyp+E/INjVLoWiJ+VPLIGCWx8VQJVn8QkidOinteZsx7D/SB5EpR5uZNYkdp5i4Umdf8ynX3iIoegyP5jrL3Uzxl/6NxdIg6rJksrnDdreliBYC6tLoQSYJtezi4tjvnOD0jLgeY0AWtmeIsuYtbThjZqWrqEMbL4B/kbgUt36HwUfPedFD0BXQJbhrnn6TnfxeIVzOErH5c25iq1jiDbB329w1U7l3tEHCJhbpZiS2MH8WClS+zm" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=debug msg="completed challenge" Aug 31 11:00:13 volumio go-librespot[23615]: time="2025-08-31T11:00:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:13 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:15 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=4s Aug 31 11:00:15 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:15 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:15 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 e0 00 00 f0 00 Aug 31 11:00:15 volumio kernel: critical medium error, dev sda, sector 1207781856 op 0x0:(READ) flags 0x84700 phys_seg 30 prio class 3 Aug 31 11:00:15 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:15 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189971. Aug 31 11:00:16 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:16 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:16 volumio go-librespot[23623]: go-librespot daemon starting... Aug 31 11:00:16 volumio go-librespot[23623]: time="2025-08-31T11:00:16+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:16 volumio go-librespot[23623]: time="2025-08-31T11:00:16+02:00" level=debug msg="app state loaded" Aug 31 11:00:16 volumio go-librespot[23623]: time="2025-08-31T11:00:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+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]" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+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]" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+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]" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+02:00" level=info msg="zeroconf server listening on port 42731" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+02:00" level=debug msg="obtained new client token: AAD0VtmdZ3Y2GJ+THOLbKyS0JdcNCbdB7uQb6e5y6G61NIGoL8C4y1Qs/DX1dg/6MFBTicndRCArLC1bFNpO210M66Td49dPIdffp1ypQ+bmeVQvz7qirUwxzVP/bRoZzzY+S56cjow6IWfY/RZktnJ5dKQuBrzLMD9zYzKpKlQT5v9frzqYxpSINMqhKimpZZGAMXi4ae8TeIBGqE+AURp/eAbqLqr1TYqWWBGvl/4uu6kf7ik02w==" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+02:00" level=debug msg="completed challenge" Aug 31 11:00:17 volumio go-librespot[23623]: time="2025-08-31T11:00:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:17 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:18 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:18 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:19 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:19 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:19 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:19 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:19 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:20 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Aug 31 11:00:20 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand rescan Aug 31 11:00:20 volumio volumio[1054]: info: sendMpdCommand rescan took 2 milliseconds Aug 31 11:00:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189972. Aug 31 11:00:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:20 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:20 volumio go-librespot[23632]: go-librespot daemon starting... Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=debug msg="app state loaded" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+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]" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+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]" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+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]" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=info msg="zeroconf server listening on port 34693" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=debug msg="obtained new client token: AAC81J6dNIh8c2B3f9t79NIzCvlpp2byU0nQDbqAHAqWDWmFl7qIuYccZ6rxplmwZ8AjnqaBHClBEV77W6gBiXeL0bv1jxJN0yOlaDtvamVLX+877XmmT0BbbdCaGeJY0XigsKjDVbwFNFQ/5/PQJRkDD/O145EUvKkYIYJdSLK+/k6YLBEsSrnxnYx6JfkaxhYS6CYQt2MD4QXu2TUxbs0WpCY9jX+02bHMDLmNLB0TBmE+SQu4acMN" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=debug msg="completed challenge" Aug 31 11:00:20 volumio go-librespot[23632]: time="2025-08-31T11:00:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:21 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:21 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:21 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:22 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:22 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:22 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:22 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:22 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189973. Aug 31 11:00:24 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:24 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:24 volumio go-librespot[23698]: go-librespot daemon starting... Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=debug msg="app state loaded" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+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]" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+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]" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+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]" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=info msg="zeroconf server listening on port 43923" Aug 31 11:00:24 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=debug msg="new websocket client" Aug 31 11:00:24 volumio volumio[1054]: info: Connection to go-librespot Websocket established Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=debug msg="obtained new client token: AADBury/qwDTxXmvlto4PEHiVRxEB9W9QcDuhhNoQUC+oCsjQVEY5s0QWl5s0QQecxBeAtUACGx3+1j8fVnmvQrZscoDJZnKQxuRw0dp24WT3vPgYIkb+QrZeY8LmMs9G7MVlSpt7HwcuJDPZ1elrligc2JVQ5R3G3aqDuud0X0LoCTLLY8C0up628+s6yc+zFHzNV+AXXhK3tJdlUXQoH+80GJRfjciCSAKU1l4mVnKTitvrGgwLWfs" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=debug msg="completed challenge" Aug 31 11:00:24 volumio go-librespot[23698]: time="2025-08-31T11:00:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:24 volumio volumio[1054]: info: Connection to go-librespot Websocket closed Aug 31 11:00:25 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:25 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:25 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:25 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:25 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:25 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:27 volumio volumio[1054]: info: Getting Spotify volume Aug 31 11:00:27 volumio volumio[1054]: (node:1054) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:27 volumio volumio[1054]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 31 11:00:27 volumio volumio[1054]: (node:1054) 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: 21877) Aug 31 11:00:27 volumio volumio[1054]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 31 11:00:27 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 11:00:27 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:27 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:27 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189974. Aug 31 11:00:27 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:27 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:27 volumio go-librespot[23706]: go-librespot daemon starting... Aug 31 11:00:27 volumio go-librespot[23706]: time="2025-08-31T11:00:27+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:27 volumio go-librespot[23706]: time="2025-08-31T11:00:27+02:00" level=debug msg="app state loaded" Aug 31 11:00:27 volumio go-librespot[23706]: time="2025-08-31T11:00:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:28 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:28 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:28 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:28 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:28 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+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]" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+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]" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+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]" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+02:00" level=info msg="zeroconf server listening on port 41895" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+02:00" level=debug msg="obtained new client token: AABJIcDdUbgWdPVZeMtR1bhSmcpTdiin/XPFLhGe0jR5d+0cckPtflAllO1q1pmCYf4lJUn+6af47RmbPw80mQDQjQsDR55FU4XAMhEfYx5D53/mMIhOolpHYe3mLTeQ0KPnfv9NFTsN95caRaRp11lYBGtLdG0yTNhLC/8uos0JczLioz+9/IHqUAuabRr99SU4XZ5VbKE8lCXbTSndNAdVDivpioMcpRUdEKxefccfBS8fDLVOyg==" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+02:00" level=debug msg="completed challenge" Aug 31 11:00:28 volumio go-librespot[23706]: time="2025-08-31T11:00:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:29 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:30 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:30 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:30 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:30 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:30 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:30 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:30 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189975. Aug 31 11:00:31 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:31 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:31 volumio go-librespot[23714]: go-librespot daemon starting... Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+02:00" level=debug msg="app state loaded" Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+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]" Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+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]" Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+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]" Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+02:00" level=info msg="zeroconf server listening on port 44331" Aug 31 11:00:31 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 11:00:31 volumio go-librespot[23714]: time="2025-08-31T11:00:31+02:00" level=debug msg="obtained new client token: AADDNS/plTEoegwdS0Fys+m2Hk00CfrFNdJNI51XsP0MdHpFLPQTTL0c73n31Ce6S9leK9Dcnt3wYBrYS9huYfAu4RnFCYdPL8bU9a6WUGO+oXekL8VUREXNRKHEA55cJRjGKTB1b0cw+luxZaMEh3LcmodDbi27E+vJCDGZ6ENsPopoHr/79urJF6PtBumM0hNLimFaeAQ6Nwk05oNHnfLAGdSsNabCYLONtneGdSr5HzvTZenfLtjG" Aug 31 11:00:32 volumio go-librespot[23714]: time="2025-08-31T11:00:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:32 volumio go-librespot[23714]: time="2025-08-31T11:00:32+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:32 volumio go-librespot[23714]: time="2025-08-31T11:00:32+02:00" level=debug msg="completed challenge" Aug 31 11:00:32 volumio go-librespot[23714]: time="2025-08-31T11:00:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:33 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:33 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:33 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:33 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:33 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:33 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:33 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189976. Aug 31 11:00:35 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:35 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:35 volumio go-librespot[23736]: go-librespot daemon starting... Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=debug msg="app state loaded" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+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]" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+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]" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+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]" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=info msg="zeroconf server listening on port 38275" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=debug msg="obtained new client token: AAC0wwjVpGA0FC5xeRK7iugHw6wOaSWVg+GBPnr/dpVlL9gcyF0RZKrJvJBu/fPLpRYwWN5bEaDRy5fUC0Z0lxzU1+7YcG/H4ain7D6veeHYPdfQZS+omNdvT5XYmXuQQk+L0KVWIAugQUWZolvW2vJ585+8MAGNsGmGzJpaWSagCQKVeUmEvpMQylUVXxh+kJx7O0GEInBxorwYfDi4Hd/B2Ov/XI1pyVcH4tyFF5P8aIH4u+AA+cbX" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:35 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 11:00:35 volumio volumio[1054]: info: CURURI: music-library Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=debug msg="completed challenge" Aug 31 11:00:35 volumio volumio[1054]: info: Preload queue cleared Aug 31 11:00:35 volumio go-librespot[23736]: time="2025-08-31T11:00:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:36 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:36 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:36 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:36 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 fd 49 00 00 00 08 00 Aug 31 11:00:36 volumio kernel: critical medium error, dev sda, sector 1207781632 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Aug 31 11:00:36 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:36 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:37 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 11:00:37 volumio volumio[1054]: info: CURURI: music-library/NAS Aug 31 11:00:37 volumio volumio[1054]: error: Failed LSINFO: null Aug 31 11:00:37 volumio volumio[1054]: info: Preload queue cleared Aug 31 11:00:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189977. Aug 31 11:00:38 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:38 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:38 volumio go-librespot[23744]: go-librespot daemon starting... Aug 31 11:00:38 volumio go-librespot[23744]: time="2025-08-31T11:00:38+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:38 volumio go-librespot[23744]: time="2025-08-31T11:00:38+02:00" level=debug msg="app state loaded" Aug 31 11:00:38 volumio go-librespot[23744]: time="2025-08-31T11:00:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+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]" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+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]" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+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]" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+02:00" level=info msg="zeroconf server listening on port 35407" Aug 31 11:00:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:39 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 41 09 20 00 00 08 00 Aug 31 11:00:39 volumio kernel: critical medium error, dev sda, sector 1195444512 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 3 Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+02:00" level=debug msg="obtained new client token: AAAXimgvWsnLRe94OuXF55pCUxLvObxLSd+lA7ctWDOZ2MhZ6F0HgMDMcDwY+JpP4QPH8juMcG6RykVDGmqFmftiKS01lEKDJIyQEaro2bW8l9Axczs+ZNn7i7gdXpRldkvUP5mwyBaAN1prF7Im/aqYI+uk7R/KOytQZ4nVEFqf0nTgxj20yxgTE5I0Pfhn5356HUOrYKlB6MSjD6DUol+0amXnDQQ/CUXxxsFuJuterUmeRq1ySA==" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+02:00" level=debug msg="completed challenge" Aug 31 11:00:39 volumio go-librespot[23744]: time="2025-08-31T11:00:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:39 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:39 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:41 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 11:00:41 volumio volumio[1054]: info: CURURI: music-library/USB Aug 31 11:00:41 volumio volumio[1054]: info: Preload queue cleared Aug 31 11:00:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:41 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 41 09 20 00 00 08 00 Aug 31 11:00:41 volumio kernel: critical medium error, dev sda, sector 1195444512 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 3 Aug 31 11:00:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189978. Aug 31 11:00:42 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:42 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:42 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:42 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:42 volumio go-librespot[23767]: go-librespot daemon starting... Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+02:00" level=debug msg="app state loaded" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+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]" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+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]" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+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]" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+02:00" level=info msg="zeroconf server listening on port 33119" Aug 31 11:00:42 volumio go-librespot[23767]: time="2025-08-31T11:00:42+02:00" level=debug msg="obtained new client token: AAAeb4waPWLzICWXBsW/h24bpO2abz5Qdl4v/BaEOlkglLGdPmy4QGH0Zkwt3JXP88kHv6ZpcVXt6AiOeJ/ES64VmWUmbsLAnpNM2IIfuc0tqXWjb+B8iWjYeBwxg1i5bZfc3RruhyHQ5Z8Vjpuw13sdMWo7Ta6cC2OaUW8t7qPsa78MyZ/vz2O8b8E5J2TD55Nx/LJWKs7NDcbnTlQBxz+7phe202hhKykGTCNskDZvsGc0/m/H/V8l" Aug 31 11:00:43 volumio go-librespot[23767]: time="2025-08-31T11:00:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:43 volumio go-librespot[23767]: time="2025-08-31T11:00:43+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:43 volumio go-librespot[23767]: time="2025-08-31T11:00:43+02:00" level=debug msg="completed challenge" Aug 31 11:00:43 volumio go-librespot[23767]: time="2025-08-31T11:00:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:44 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:44 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:44 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:44 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 41 09 20 00 00 08 00 Aug 31 11:00:44 volumio kernel: critical medium error, dev sda, sector 1195444512 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 3 Aug 31 11:00:45 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:45 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:45 volumio volumio[1054]: info: CoreCommandRouter::volumioGetState Aug 31 11:00:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189979. Aug 31 11:00:46 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:46 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:46 volumio go-librespot[23778]: go-librespot daemon starting... Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=debug msg="app state loaded" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+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]" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+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]" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+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]" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=info msg="zeroconf server listening on port 42653" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=debug msg="obtained new client token: AABonpXm+Z6ujF0h7SNPuw6OG6FjoqH+w/mH4KFpuG7SPE3idiNIPqKgqfWNzkJZGp1tu8sQlb8/PkE5KTxllO2riIlyLkbt8p4l445LJH4s2S4lSk/4yqgCaT5xDy4KsgjsmNjiaYD7PLANa9D97oOwb0m6JCsyG8Hc/GHugyW3Owt7X85Od8IqOGsn/iUP2MtihHRJulG3PqAKcSRwVjy2x7bOuALEz3JhqxYODClvgxr3YEHq98oB" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=debug msg="completed challenge" Aug 31 11:00:46 volumio go-librespot[23778]: time="2025-08-31T11:00:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:47 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:47 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:47 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:47 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 41 09 20 00 00 08 00 Aug 31 11:00:47 volumio kernel: critical medium error, dev sda, sector 1195444512 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 3 Aug 31 11:00:47 volumio volumio[1054]: info: MPD Database updated - AlbumList cache refreshed Aug 31 11:00:47 volumio volumio[1054]: info: Aug 31 11:00:47 volumio volumio[1054]: ---------------------------- MPD announces state update: database Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: Aug 31 11:00:47 volumio volumio[1054]: ---------------------------- MPD announces state update: update Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: MPD Database updated - AlbumList cache refreshed Aug 31 11:00:47 volumio volumio[1054]: info: Aug 31 11:00:47 volumio volumio[1054]: ---------------------------- MPD announces state update: database Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: Aug 31 11:00:47 volumio volumio[1054]: ---------------------------- MPD announces state update: update Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: MPD Database updated - AlbumList cache refreshed Aug 31 11:00:47 volumio volumio[1054]: info: Aug 31 11:00:47 volumio volumio[1054]: ---------------------------- MPD announces state update: database Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: Aug 31 11:00:47 volumio volumio[1054]: ---------------------------- MPD announces state update: update Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::getState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::sendMpdCommand status Aug 31 11:00:47 volumio volumio[1054]: info: sendMpdCommand status took 145 milliseconds Aug 31 11:00:47 volumio volumio[1054]: info: sendMpdCommand status took 144 milliseconds Aug 31 11:00:47 volumio volumio[1054]: info: sendMpdCommand status took 144 milliseconds Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:47 volumio volumio[1054]: info: Command Router : Notfying DB Updatetrue Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:47 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:47 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:47 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:47 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:47 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:47 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:47 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:47 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:47 volumio volumio[1054]: info: ------------------------------ 284ms Aug 31 11:00:47 volumio volumio[1054]: info: ------------------------------ 284ms Aug 31 11:00:47 volumio volumio[1054]: info: sendMpdCommand status took 346 milliseconds Aug 31 11:00:47 volumio volumio[1054]: info: sendMpdCommand status took 345 milliseconds Aug 31 11:00:47 volumio volumio[1054]: info: sendMpdCommand status took 345 milliseconds Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:47 volumio volumio[1054]: info: Command Router : Notfying DB Updatetrue Aug 31 11:00:47 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:47 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:48 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:48 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:48 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:48 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:48 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: ------------------------------ 438ms Aug 31 11:00:48 volumio volumio[1054]: info: ------------------------------ 438ms Aug 31 11:00:48 volumio volumio[1054]: info: sendMpdCommand status took 507 milliseconds Aug 31 11:00:48 volumio volumio[1054]: info: sendMpdCommand status took 506 milliseconds Aug 31 11:00:48 volumio volumio[1054]: info: sendMpdCommand status took 507 milliseconds Aug 31 11:00:48 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:48 volumio volumio[1054]: info: Command Router : Notfying DB Updatetrue Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::Close All Modals sent Aug 31 11:00:48 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:48 volumio volumio[1054]: verbose: ControllerMpd::parseState Aug 31 11:00:48 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:48 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:48 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: ControllerMpd::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::servicePushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: CorePlayQueue::getTrack 0 Aug 31 11:00:48 volumio volumio[1054]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 11:00:48 volumio volumio[1054]: verbose: CURRENT POSITION 0 Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState stateService stop Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::syncState currentStatus pause Aug 31 11:00:48 volumio volumio[1054]: info: CoreStateMachine::pushState Aug 31 11:00:48 volumio volumio[1054]: info: CoreCommandRouter::volumioPushState Aug 31 11:00:48 volumio volumio[1054]: info: ------------------------------ 651ms Aug 31 11:00:48 volumio volumio[1054]: info: ------------------------------ 652ms Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Aug 31 11:00:48 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:48 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189980. Aug 31 11:00:50 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:50 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:50 volumio go-librespot[23793]: go-librespot daemon starting... Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=debug msg="app state loaded" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+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]" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+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]" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+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]" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=info msg="zeroconf server listening on port 37901" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=debug msg="obtained new client token: AACftOcWW+WQWBDMpmYgx8vRI64t9l4oRegBxEOzXYsnkmCVQW24BKt67bcnppwHxYepGaaYu+pxYtOl/A7o4OADlnwxIlMh2FueTP7jXt0ipAqtHB+Ydfd4lNyaiF1nQ0PEIggYtEoUlsxmYKAzj0sBpupdvv8VUaToVGa/DP/daJnbC0LpwEMFbvPTlWKcNuQDYE5ev6XojNIxeFn5x3asbInQB2MyQ/5baknwjmUKaRjVVIFNlyDz" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=debug msg="completed challenge" Aug 31 11:00:50 volumio go-librespot[23793]: time="2025-08-31T11:00:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:51 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:51 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 11:00:52 volumio volumio[1054]: info: Retrieving Cloud Streaming UI Aug 31 11:00:52 volumio volumio[1054]: info: Getting Tidal Cloud Configuration Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 11:00:52 volumio volumio[1054]: info: Getting Qobuz Cloud Configuration Aug 31 11:00:52 volumio volumio[1054]: info: Asking plugin for UI Config Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 11:00:52 volumio volumio[1054]: info: Getting Spotify Cloud Configuration Aug 31 11:00:52 volumio volumio[1054]: info: Asking plugin for UI Config Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 11:00:52 volumio volumio[1054]: info: Saving Spotify Acccount Aug 31 11:00:52 volumio volumio[1054]: info: Got it Aug 31 11:00:52 volumio volumio[1054]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Aug 31 11:00:52 volumio volumio[1054]: info: Got Tidal Cloud Configuration Aug 31 11:00:52 volumio volumio[1054]: info: Got it Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 11:00:52 volumio volumio[1054]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:52 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 31 11:00:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189981. Aug 31 11:00:53 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:53 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:53 volumio go-librespot[23818]: go-librespot daemon starting... Aug 31 11:00:53 volumio go-librespot[23818]: time="2025-08-31T11:00:53+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:53 volumio go-librespot[23818]: time="2025-08-31T11:00:53+02:00" level=debug msg="app state loaded" Aug 31 11:00:53 volumio go-librespot[23818]: time="2025-08-31T11:00:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+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]" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+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]" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+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]" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+02:00" level=info msg="zeroconf server listening on port 34495" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+02:00" level=debug msg="obtained new client token: AADizC4h3pn86YiU2rCtMWkxIm+A9fZ2jR/KvWoCAF/z/ITLWOhAIbHSk8+npFXcYs0FCc/L5BfwTCbCxeHwGynuEoaUV+M8fTPPgj2lq41P28N5DEgi3s+9jKf0fkHDZ9LxaxfiQ14aZFY5ccDyP+U7VjeDnf4jqwdXdjLZb8y62AEW7W+k25O5waFeNuPTRO4IuuAXPgTfsPyCKSxO98OHT2jQhJCjjffaNF2VlJ7rc+og//7gNA==" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+02:00" level=debug msg="completed challenge" Aug 31 11:00:54 volumio go-librespot[23818]: time="2025-08-31T11:00:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:54 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:54 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:55 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Aug 31 11:00:55 volumio sudo[23827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount /mnt/NAS/etrayz Aug 31 11:00:55 volumio sudo[23827]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 11:00:55 volumio systemd[1]: mnt-NAS-etrayz.mount: Succeeded. Aug 31 11:00:55 volumio sudo[23827]: pam_unix(sudo:session): session closed for user root Aug 31 11:00:55 volumio volumio[1054]: info: Share etrayz successfully unmounted Aug 31 11:00:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 31 11:00:56 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 31 11:00:56 volumio kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=2s Aug 31 11:00:56 volumio kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x3 [current] Aug 31 11:00:56 volumio kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x11 ASCQ=0x0 Aug 31 11:00:56 volumio kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 47 41 09 20 00 00 08 00 Aug 31 11:00:56 volumio kernel: critical medium error, dev sda, sector 1195444512 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 3 Aug 31 11:00:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 11:00:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189982. Aug 31 11:00:57 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 11:00:57 volumio volumio[1054]: info: Initializing connection to go-librespot Websocket Aug 31 11:00:57 volumio volumio[1054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 11:00:57 volumio systemd[1]: Started go-librespot Daemon. Aug 31 11:00:57 volumio go-librespot[23830]: go-librespot daemon starting... Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+02:00" level=info msg="running go-librespot 0.2.0" Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+02:00" level=debug msg="app state loaded" Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 11:00:57 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Aug 31 11:00:57 volumio volumio[1054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00: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-gae2.spotify.com:80]" Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+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]" Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+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]" Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+02:00" level=info msg="zeroconf server listening on port 40137" Aug 31 11:00:57 volumio go-librespot[23830]: time="2025-08-31T11:00:57+02:00" level=debug msg="obtained new client token: AABKjArRiYz7gXmRRcOdRjXv1oCQQpkYAANaZf3QHWw1biBDcCP8KWCYlOpsnlDlt6jxY4L911fvf7YVGtKU/2dojj49MIJxN6GxXyJJ15Qu1hiUwp5Eklo9Vkj6eq8Hd3AUUeezRbZGHDYj6ZpZWOKXVfUKZ+1V3l0jmFcxe9yva7bFwMtoyEjAe7G0cjtkPWY4qKRsiQaiRb1xpH8H6i2TKlJEf33b26GFMhuzqeS8+DEb1AlKMbDN" Aug 31 11:00:58 volumio go-librespot[23830]: time="2025-08-31T11:00:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 11:00:58 volumio go-librespot[23830]: time="2025-08-31T11:00:58+02:00" level=debug msg="completed keyexchange" Aug 31 11:00:58 volumio go-librespot[23830]: time="2025-08-31T11:00:58+02:00" level=debug msg="completed challenge" Aug 31 11:00:58 volumio go-librespot[23830]: time="2025-08-31T11:00:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Aug 31 11:00:58 volumio volumio[1054]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 11:00:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 11:00:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 11:00:58 volumio volumio[1054]: Error: getaddrinfo -3007 Aug 31 11:00:58 volumio volumio[1054]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Aug 31 11:00:58 volumio volumio[1054]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Aug 31 11:00:58 volumio volumio[1054]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Aug 31 11:00:58 volumio volumio[1054]: code: -3007, Aug 31 11:00:58 volumio volumio[1054]: errno: -3007, Aug 31 11:00:58 volumio volumio[1054]: syscall: 'getaddrinfo' Aug 31 11:00:58 volumio volumio[1054]: } Aug 31 11:00:58 volumio volumio[1054]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 11:00:58 volumio sudo[23850]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 10:59 Aug 31 11:00:58 volumio sudo[23850]: 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"