-- Logs begin at Mon 2024-03-25 21:22:18 GMT, end at Sat 2024-09-07 17:47:31 BST. -- Sep 07 17:46:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 274. Sep 07 17:46:00 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:00 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:00 minidsp-shd go-librespot[7188]: Librespot-go daemon starting... Sep 07 17:46:00 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:00+01:00" level=info msg="generated new device id: 634a85524ddee835f79dd18d68054e1a68ec728b" Sep 07 17:46:00 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:00+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:01 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:01+01:00" level=debug msg="obtained new client token: AAAcdl1oWGO0wsX0vlhmDyVIZwHhtpcuUyzfiNjDzHpV4Uyj9//88HtOS2UZ0MANiAhuhWXEwtZEOH66qciCvlkY8633ulnLgtWw6l93PSIPfVnmtcd5ZrasoRdwscI1BwaOWYl0k/0s2KFQNiVxMlD8gQx5OorzSqNCBBEtkPiSHE7Vs0ekqjZ03zC8cp3BAabiUW0rX1i0g1J8Gw8z+mnyEvntKMKVHQY6oewGT76YBkqfGQIGYz5FgIhD" Sep 07 17:46:01 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:01+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:01 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:01+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:01 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:01+01:00" level=debug msg="completed challenge" Sep 07 17:46:01 minidsp-shd go-librespot[7188]: time="2024-09-07T17:46:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:02 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:02 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 275. Sep 07 17:46:05 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:05 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:05 minidsp-shd go-librespot[7243]: Librespot-go daemon starting... Sep 07 17:46:05 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:05+01:00" level=info msg="generated new device id: 81e6498c790e946537f78fbd324f095660332b85" Sep 07 17:46:05 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:05+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:05 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:05 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:05+01:00" level=debug msg="obtained new client token: AAD6nnsm89f8UEFMqa84wuUsNsednFvc+L15D/eeo+1NvdmQw35To4aCo8LFGyOlKr8Jg3L9oXAKrAtEbylEc6Dvvl+tnbdAjiKyF9YkWOinRjh5iMXczqR1tCwPF+DvtHwcigsL/ElKyV2CESjS14OA+8UWbhBV7idc+e+BNmOVClmizaFeR4fCLahSO00XPcODyNaHGWeQKLqHXnmYu+mu1pOQdxck/GN+Qqx3TbQsMND3lCS/eiID0SjcmkY=" Sep 07 17:46:05 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:05+01:00" level=debug msg="new websocket client" Sep 07 17:46:05 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket established Sep 07 17:46:05 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:05+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:05 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:05+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:06 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:06+01:00" level=debug msg="completed challenge" Sep 07 17:46:06 minidsp-shd go-librespot[7243]: time="2024-09-07T17:46:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:06 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket closed Sep 07 17:46:08 minidsp-shd volumio[713]: info: Getting Spotify volume Sep 07 17:46:08 minidsp-shd volumio[713]: (node:713) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:08 minidsp-shd volumio[713]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 17:46:08 minidsp-shd volumio[713]: (node:713) 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: 86) Sep 07 17:46:08 minidsp-shd volumio[713]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 17:46:08 minidsp-shd volumio[713]: info: CoreCommandRouter::volumioGetState Sep 07 17:46:08 minidsp-shd volumio[713]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 17:46:09 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:09 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 276. Sep 07 17:46:09 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:09 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:09 minidsp-shd go-librespot[7259]: Librespot-go daemon starting... Sep 07 17:46:09 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:09+01:00" level=info msg="generated new device id: d4b5e83dd1ed9a8b6a8db840f34a192089d88816" Sep 07 17:46:09 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:09+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:09 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:09+01:00" level=debug msg="obtained new client token: AAAVAdmPU4j6Kn6LgZdoQeXvAl9OSlwcTjOnnvN3fGk4rOIISMloFFW1MjRxTs2HBdUH3W4QTwIhfhKglsh/hV//JPVGa0U0ZpNO/C/Je+wyt/Q5FakxHWeMQ9JIUo3pCTCs4HVi3hxSjc1M8BGFYcItIUV7zaA4X2j1RNAY1Lx5XxCfjVlZ8o++MaWcX+OxGUKEUHNNRMPxIChzsQErephbf/JQmQLNMpTkBuakoJY8NglNp5N44UJTVOwlc3s=" Sep 07 17:46:09 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:09+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:09 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:09+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:10 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:10+01:00" level=debug msg="completed challenge" Sep 07 17:46:10 minidsp-shd go-librespot[7259]: time="2024-09-07T17:46:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:12 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:12 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 277. Sep 07 17:46:13 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:13 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:13 minidsp-shd go-librespot[7275]: Librespot-go daemon starting... Sep 07 17:46:13 minidsp-shd go-librespot[7275]: time="2024-09-07T17:46:13+01:00" level=info msg="generated new device id: 2ca20330629489db8f520419616d68a553318c32" Sep 07 17:46:13 minidsp-shd go-librespot[7275]: time="2024-09-07T17:46:13+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:13 minidsp-shd go-librespot[7275]: time="2024-09-07T17:46:13+01:00" level=debug msg="obtained new client token: AABLMDmqP0d0bKCA2PgfK43PdqNsWHvvdPUTxkSeDFWBbARD12Uvj+AW9mQdvmQrdH4m7NxWSx2aor6ztKuJmYfRD1mAGyOSDYhe9rbI2lLRozHZle9sitsw2AupMGwBTLJsvbKZVU2g0Dt1+BYMh3pQ+8PY8Lj/b4m71pgbStU3c5HUXlqnV2uDjchKheazPw5sBFRZusr3Potgv6fDpX4ZTco6AYWJ5j1qvpbZlwr3qSMvG4gF6HWJF6CtV7g=" Sep 07 17:46:13 minidsp-shd go-librespot[7275]: time="2024-09-07T17:46:13+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:14 minidsp-shd go-librespot[7275]: time="2024-09-07T17:46:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Sep 07 17:46:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:15 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:15 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 278. Sep 07 17:46:17 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:17 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:17 minidsp-shd go-librespot[7292]: Librespot-go daemon starting... Sep 07 17:46:17 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:17+01:00" level=info msg="generated new device id: 8cceee9760eb4c20ea801b69b8d496b595847a33" Sep 07 17:46:17 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:17+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:17 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:17+01:00" level=debug msg="obtained new client token: AABAtbTVWvwM6vXP0a+Ixo3x59AhjSMpGcaELWldcTF1YPPP7qziZvD2dHr/p71RKIArQjDsGH2xePF26Dz6ZRBLK0TxxGkZFNch36sdb10/z8AUfg4LmaGsjTq6VJUREOtAoM3WQcGVvOe07A/d8p1ZKtNcVLhqXB/Dtm+zVPEPNkwTwanXJ4aBXCvrJIag/ohInFfINkO6+jsKa1EvG3Wngv6MqBbM/dtZzK0MQ8NV3nuPr9pQOb0P7aGeYi4=" Sep 07 17:46:17 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:17+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:17 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:17+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:18 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:18+01:00" level=debug msg="completed challenge" Sep 07 17:46:18 minidsp-shd go-librespot[7292]: time="2024-09-07T17:46:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:18 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:18 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:21 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:21 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 279. Sep 07 17:46:21 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:21 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:21 minidsp-shd go-librespot[7308]: Librespot-go daemon starting... Sep 07 17:46:21 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:21+01:00" level=info msg="generated new device id: c3ddda53214d5720758be1d32cd7dfe9348eb6eb" Sep 07 17:46:21 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:21+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:21 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:21+01:00" level=debug msg="obtained new client token: AADkreW7QMK1oOqdTaqa59NV+KI76nt/IajCpTLJ4BR7eQHOYIOysS8VPbT7mVhpAXVypNOIES2LQnI6s/sW4J7P5CaV5wRVRLGkD8CgORcO+5chfTq9T6BtTnad0UzBsdA+3/g6ZowQq+lgnXcRn+Fe4Uy8k9JDL2P2WB83rzyux886DVZ7ZDlXV84+DYNlcdfqcUe2qnLp5aFZkT4aDKKjusa/m9QL0gCyth5il6Moqx2jzNGsPIJqLlYLqbs=" Sep 07 17:46:21 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:21+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:21 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:21+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:22 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:22+01:00" level=debug msg="completed challenge" Sep 07 17:46:22 minidsp-shd go-librespot[7308]: time="2024-09-07T17:46:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:22 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 07 17:46:22 minidsp-shd volumio[713]: info: handleBrowseUri took 96 milliseconds Sep 07 17:46:22 minidsp-shd volumio[713]: info: Preload queue cleared Sep 07 17:46:22 minidsp-shd volumio[713]: info: Preload queue cleared Sep 07 17:46:24 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:24 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:25 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 07 17:46:25 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 07 17:46:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 280. Sep 07 17:46:25 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:25 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:25 minidsp-shd go-librespot[7325]: Librespot-go daemon starting... Sep 07 17:46:25 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:25+01:00" level=info msg="generated new device id: 3c8e9eecdc2ef2c0dcbb260a3c78fde1a18f69eb" Sep 07 17:46:25 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:25+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:25 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:25+01:00" level=debug msg="obtained new client token: AAAy5vgEOAJ5sD95Cy0UyDiHjQRMlf/v8u6FdCESyqCsu1YjSxr4yiOy6VfN+Bi1WHfPzi5DPEQEzGLCDYFRMCU2hbJ9NDaafanNo301iRycAyNfVYT23x+QlJp40spcyJy12fOryIEHuu5TB4psmSCyiSNATznkq270AYMWPdVjsttQN4giLC5VhPTy30YGzMNAeAciUj4J3UUm9BqTDz37gvJ0LBXkClGLz6C/Qe0xbo/QvwNFlGk5tTiZst0=" Sep 07 17:46:26 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:26+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:26 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:26+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:26 minidsp-shd volumio[713]: info: handleBrowseUri took 974 milliseconds Sep 07 17:46:26 minidsp-shd volumio[713]: info: handleBrowseUri took 855 milliseconds Sep 07 17:46:26 minidsp-shd volumio[713]: info: Preload queue cleared Sep 07 17:46:26 minidsp-shd volumio[713]: info: Preload queue cleared Sep 07 17:46:26 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:26+01:00" level=debug msg="completed challenge" Sep 07 17:46:26 minidsp-shd go-librespot[7325]: time="2024-09-07T17:46:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:27 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:27 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 281. Sep 07 17:46:29 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:29 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:29 minidsp-shd go-librespot[7341]: Librespot-go daemon starting... Sep 07 17:46:29 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:29+01:00" level=info msg="generated new device id: 8f1c9f103bacb05b7171804c3cf0a62d206b3915" Sep 07 17:46:29 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:29+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:30 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:30 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:30+01:00" level=debug msg="obtained new client token: AAAnyNCRteZbMgG4VXYcC2pGo/HXPNMrE+G+mfcTy1sL8l+mCOm5RzLsGJMUvrxLrXxIckK1hlFIMLVeIXMgpiN42DLbk8XMxAJRc6npTyLi/dwyx4s0GB5sFV27sj2dXWb9j6J8nR/eiIOtiGEMTBzGp27zMxmfhvXGzibiBM/FOXE63cxOI/JkDJiCJXij/040C2fS21Z9+nj774rgA19+96iDLj8DdgBx8/HBZgnyU2H1CICyeuUQBQD6" Sep 07 17:46:30 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:30+01:00" level=debug msg="new websocket client" Sep 07 17:46:30 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket established Sep 07 17:46:30 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:30+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:30 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:30+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:30 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:30+01:00" level=debug msg="completed challenge" Sep 07 17:46:30 minidsp-shd go-librespot[7341]: time="2024-09-07T17:46:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:30 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket closed Sep 07 17:46:33 minidsp-shd volumio[713]: info: Getting Spotify volume Sep 07 17:46:33 minidsp-shd volumio[713]: (node:713) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:33 minidsp-shd volumio[713]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 17:46:33 minidsp-shd volumio[713]: (node:713) 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: 87) Sep 07 17:46:33 minidsp-shd volumio[713]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 17:46:33 minidsp-shd volumio[713]: info: CoreCommandRouter::volumioGetState Sep 07 17:46:33 minidsp-shd volumio[713]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 17:46:33 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:33 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 282. Sep 07 17:46:34 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:34 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:34 minidsp-shd go-librespot[7357]: Librespot-go daemon starting... Sep 07 17:46:34 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:34+01:00" level=info msg="generated new device id: d77bc7297e316f95bced2e46a3f9f6d9d70cfb2b" Sep 07 17:46:34 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:34+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:34 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:34+01:00" level=debug msg="obtained new client token: AAA6sWYEqjY2H8ST/+hu11mcVT586TKPoR5r6o68957j1NCjlymJmfmH1vZ1UBXzcuZEy2btPB8IBZDa3wOl4BPXdrjPuLIDZeYFk6ei54NpbVZM58aJtls8XiuaHIFpwo19JoWLTQPyyIVNyBYXxA9jBuRzFfI0Q/cMxug+P+axa+2/53NJW8M5L/C8e0UGTz58Gb/iU/kdlIr7rn998SYD1igVpckSApUpVamvNLAz0AZVvf3idgldvzcl998=" Sep 07 17:46:34 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:34+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:34 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:34+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:34 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 07 17:46:35 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:35+01:00" level=debug msg="completed challenge" Sep 07 17:46:35 minidsp-shd go-librespot[7357]: time="2024-09-07T17:46:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:35 minidsp-shd volumio[713]: info: handleBrowseUri took 755 milliseconds Sep 07 17:46:35 minidsp-shd volumio[713]: info: Preload queue cleared Sep 07 17:46:36 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:36 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 283. Sep 07 17:46:38 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:38 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:38 minidsp-shd go-librespot[7373]: Librespot-go daemon starting... Sep 07 17:46:38 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:38+01:00" level=info msg="generated new device id: 94913e5c95995f29cffb487a07d724a02ab46739" Sep 07 17:46:38 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:38+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:38 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:38+01:00" level=debug msg="obtained new client token: AADRGRHtmOn+Dpow9WOZEDwyBgbfCXwz+llHjMjHVpRDu3YxT5WD+u/V8lOij/69XI+3tIRzCmA1PlnK/TWQ5adngwbhQJv22AgMdf7e7Pc1JXOnVMvj8AJfQen0MydLkYLbHmbTlQjt8buVVhVum38aGKqv5yLTs11qa/m/UT+i2BsUL1C9vi/FesadO/zT2a5qd3G8AUQxGRVEnsR5P02kjwINrvqK0Kh+oDZGPC16/uum3E49vDpqX1TBspI=" Sep 07 17:46:38 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:38+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 17:46:38 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:38+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:39 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:39+01:00" level=debug msg="completed challenge" Sep 07 17:46:39 minidsp-shd go-librespot[7373]: time="2024-09-07T17:46:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:39 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:39 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:39 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:39 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:42 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:42 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 284. Sep 07 17:46:42 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:42 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:42 minidsp-shd go-librespot[7391]: Librespot-go daemon starting... Sep 07 17:46:42 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:42+01:00" level=info msg="generated new device id: dc187c1c4d2c6f7ee7136f2ebccb6dd667f97442" Sep 07 17:46:42 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:42+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:42 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:42 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:42+01:00" level=debug msg="new websocket client" Sep 07 17:46:42 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket established Sep 07 17:46:42 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:42+01:00" level=debug msg="obtained new client token: AABl3a2PMuFbx3uitxxwrmaZv4HdmpTGo76/wvy/6pOWyCse/fbbIeXjyakCpgcNSTZHKSt1Hwrb11DNcB3jXZ6BckEKuGW1pK8Es0r7k6EFueRQ5qlzlx49+nKHkyqpkFmUzM2Q1El9SAWQRNQk3QN0DvWNTjbKo4TEJlulyFVVUA+Dge1LbNpIDfZP0I6QOSuzYdEk4KEdGpVI0GPf/FheccQzu79Ko8SAo6Eonki0ctzZgPTPlcFMwMg3DQA=" Sep 07 17:46:43 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:43+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:43 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:43+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:43 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:43+01:00" level=debug msg="completed challenge" Sep 07 17:46:43 minidsp-shd go-librespot[7391]: time="2024-09-07T17:46:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:43 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket closed Sep 07 17:46:45 minidsp-shd volumio[713]: info: Getting Spotify volume Sep 07 17:46:45 minidsp-shd volumio[713]: (node:713) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:45 minidsp-shd volumio[713]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 17:46:45 minidsp-shd volumio[713]: (node:713) 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: 88) Sep 07 17:46:45 minidsp-shd volumio[713]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 17:46:45 minidsp-shd volumio[713]: info: CoreCommandRouter::volumioGetState Sep 07 17:46:45 minidsp-shd volumio[713]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 17:46:46 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:46 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 285. Sep 07 17:46:46 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:46 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:46 minidsp-shd go-librespot[7408]: Librespot-go daemon starting... Sep 07 17:46:46 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:46+01:00" level=info msg="generated new device id: 1ba143dab325052d3e211a8a6990d76a909dc7b7" Sep 07 17:46:46 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:46+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:47 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:47+01:00" level=debug msg="obtained new client token: AAAHGka8/jqQc9yug0tKCODZxyT1T7Ft758R1EV/EYQylYCAYjNqCf39dL/gYfqkcItY4LtV2UNMrF4U0dXW1mByojUm3j6I7PY4BQJqKxcF8N5vUMUygXkJMbXnk35+kM1a+wsYnV3smEEMVXEoGlW3lNuhEbL+6Y2WRt0Qo/OmEYI+MtNlZDmXzAgPwLtwd/WdA70CV/eug+BWI3vkVcjPP2U6cMQQCcRiBPaen55bjnjzPFhp4NAj9S1y" Sep 07 17:46:47 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:47+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:47 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:47+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:47 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:47+01:00" level=debug msg="completed challenge" Sep 07 17:46:47 minidsp-shd go-librespot[7408]: time="2024-09-07T17:46:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:47 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:47 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:49 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:49 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 286. Sep 07 17:46:51 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:51 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:51 minidsp-shd go-librespot[7424]: Librespot-go daemon starting... Sep 07 17:46:51 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:51+01:00" level=info msg="generated new device id: 4991a7117fcc3c5e2c6468560e99d702fa04dee5" Sep 07 17:46:51 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:51+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:51 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:51+01:00" level=debug msg="obtained new client token: AADhSryyRQXXw1QBi+Uo8TndQAg81Ok5K6DEVoFbXk4tQ+qYA+IuaEkX51sEjUJadXtbZDofAGWIXH1AY2QVinUEqqrV1I2zY6hvXYqXl9dvgBzGoM+MpIVIFziCiHQQhhpsiy6tiPHpWUt/9fO8ScLgkA/b0l2vDI9vPPJlYYVXKin8BXbPZ3tEY6oTHeFhmLJOHKFRATsU7ZJEpW2nfiz1w4W7bZQoG8XoOh9eVtWDAmk29T5TrKDisPQX9q0=" Sep 07 17:46:51 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:51+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:51 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:51+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:52 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:52+01:00" level=debug msg="completed challenge" Sep 07 17:46:52 minidsp-shd go-librespot[7424]: time="2024-09-07T17:46:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:52 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:52 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:55 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:55 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 287. Sep 07 17:46:55 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:55 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:55 minidsp-shd go-librespot[7440]: Librespot-go daemon starting... Sep 07 17:46:55 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:55+01:00" level=info msg="generated new device id: 1a6a696cf97529f4d3654ff24b7b177d8277e5e3" Sep 07 17:46:55 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:55+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:55 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:55+01:00" level=debug msg="obtained new client token: AAAcggseXji78LaZcbB6tWEHhB33B0H825/hkcBdBZBVrur9dHmLDE2qF5CGrswlBHDUsLSjoDp1FjdJYpGfatx82QucFwSJHgj9LgzgJXRMq3AjTycQAdb4orG73GSWJsAFGrcnummeMOpllddGaRRWgqZcn0x3O6m/IuzGImOkO4XRmKZkJWTpn2twErRNl5S3dLp015tCSUfmp+II5J0/WNlSwfURCL/kp0VNuCZUBGZ7iVMgmAb5g9tJmjA=" Sep 07 17:46:55 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:55 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:55+01:00" level=debug msg="new websocket client" Sep 07 17:46:55 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket established Sep 07 17:46:55 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:55+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:46:55 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:55+01:00" level=debug msg="completed keyexchange" Sep 07 17:46:56 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:56+01:00" level=debug msg="completed challenge" Sep 07 17:46:56 minidsp-shd go-librespot[7440]: time="2024-09-07T17:46:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:46:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:46:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:46:56 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket closed Sep 07 17:46:58 minidsp-shd volumio[713]: info: Getting Spotify volume Sep 07 17:46:58 minidsp-shd volumio[713]: (node:713) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:58 minidsp-shd volumio[713]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 17:46:58 minidsp-shd volumio[713]: (node:713) 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: 89) Sep 07 17:46:58 minidsp-shd volumio[713]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 17:46:58 minidsp-shd volumio[713]: info: CoreCommandRouter::volumioGetState Sep 07 17:46:58 minidsp-shd volumio[713]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 17:46:59 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:46:59 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:46:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:46:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 288. Sep 07 17:46:59 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:46:59 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:46:59 minidsp-shd go-librespot[7456]: Librespot-go daemon starting... Sep 07 17:46:59 minidsp-shd go-librespot[7456]: time="2024-09-07T17:46:59+01:00" level=info msg="generated new device id: 593a7c563f77118ef2cb9a8a889c789221509abc" Sep 07 17:46:59 minidsp-shd go-librespot[7456]: time="2024-09-07T17:46:59+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:46:59 minidsp-shd go-librespot[7456]: time="2024-09-07T17:46:59+01:00" level=debug msg="obtained new client token: AADtZDFgyTr5l7U1LTvt/BH4oIKI8mDWxEbuvKKOkN9WcUr+8IkVkC3bHxeUT5vbx/N8V8MMczO5/3f/r92HNb/2t3XsbRNC2G9StZ+CfCotCEgQCKliw1/M3PEXCC/bf9dTYX/G+/p58KOakdeACJ30laOMkfqHugwYaITuC0iC6Iay62+rwni8u+YZIXQlvjUwiWkHyjjdhCDJPz138l+WV0qevNha9rgd/SFB3DC6KVyVz3I5eGNIaXMaac4=" Sep 07 17:47:00 minidsp-shd go-librespot[7456]: time="2024-09-07T17:47:00+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 17:47:00 minidsp-shd go-librespot[7456]: time="2024-09-07T17:47:00+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:00 minidsp-shd go-librespot[7456]: time="2024-09-07T17:47:00+01:00" level=debug msg="completed challenge" Sep 07 17:47:00 minidsp-shd go-librespot[7456]: time="2024-09-07T17:47:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:02 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:02 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 289. Sep 07 17:47:03 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:03 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:03 minidsp-shd go-librespot[7513]: Librespot-go daemon starting... Sep 07 17:47:03 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:03+01:00" level=info msg="generated new device id: eb412b78d27d18710acf85527c6da1e851ceea67" Sep 07 17:47:03 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:03+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:04 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:04+01:00" level=debug msg="obtained new client token: AAAwfVS4Srb5mBuFsWBTT64pLSB7w7tOT/BE7jUrqdi3iU0UwfgDha5IPBI10qcC5hqlfIg2/qRrZjmY7KigcVSqcRsQETORRA6BvgoaeP2jgiGmKZghboEraGz2RgfvBZwz+uXnsbdefGW32ivbpXgtXAGPgzkO03z25M2MWp3HMMEZzuFBbJoDIVLTZicMxs0E0mEzw7Prn2a4IMJ5WKHa3AokqsanVLPVT4evzqDJf9c/Wy9QZaRNK8Kq" Sep 07 17:47:04 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:04+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:47:04 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:04+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:04 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:04+01:00" level=debug msg="completed challenge" Sep 07 17:47:04 minidsp-shd go-librespot[7513]: time="2024-09-07T17:47:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:05 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:05 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 290. Sep 07 17:47:08 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:08 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:08 minidsp-shd go-librespot[7529]: Librespot-go daemon starting... Sep 07 17:47:08 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:08+01:00" level=info msg="generated new device id: a2e0425009f2180de6568d7e186cf075464761c9" Sep 07 17:47:08 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:08+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:08 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:08+01:00" level=debug msg="obtained new client token: AABPQWJgssEsJkKGRlNuTO7NZcBSduxQssfNB6IN9+j04R862qaMNXVP9n2n5s85HsVdC7nA60/5pqQ7mKydyHaxcR+RvxVPXSI0OOD5XmBk/YwRWE/uHXpQD0L5gpmmZ3B/aWvm11kMHlcpTI4Msjq7GrM+zZWlDrgHE9lf9WbdXPSYS8PgqyLFnYnoPzk+dKIof6z/T/b6yBFJjF1adIFkfxTURp2puYObe3Q3prbOWXdCfv3+PiM9CSI25Pw=" Sep 07 17:47:08 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:08 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:08+01:00" level=debug msg="new websocket client" Sep 07 17:47:08 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket established Sep 07 17:47:08 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:08+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 17:47:08 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:08+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:09 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:09+01:00" level=debug msg="completed challenge" Sep 07 17:47:09 minidsp-shd go-librespot[7529]: time="2024-09-07T17:47:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:09 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket closed Sep 07 17:47:11 minidsp-shd volumio[713]: info: Getting Spotify volume Sep 07 17:47:11 minidsp-shd volumio[713]: (node:713) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:11 minidsp-shd volumio[713]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 17:47:11 minidsp-shd volumio[713]: (node:713) 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: 90) Sep 07 17:47:11 minidsp-shd volumio[713]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 17:47:11 minidsp-shd volumio[713]: info: CoreCommandRouter::volumioGetState Sep 07 17:47:11 minidsp-shd volumio[713]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 17:47:12 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:12 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 291. Sep 07 17:47:12 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:12 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:12 minidsp-shd go-librespot[7545]: Librespot-go daemon starting... Sep 07 17:47:12 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:12+01:00" level=info msg="generated new device id: 4d112c5a1f873904ca4c69211b6e10846a64ceb0" Sep 07 17:47:12 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:12+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:12 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:12+01:00" level=debug msg="obtained new client token: AACg50jR4tKNFy0ip+yd/v1BXVhLcL9Ylkpsj7XSwGtPAufxTL0xspp+AoxuW+KeVSCLEVVO/SGiKp+S6x6fwA5WcJwiyFpUtFH/JOwvyiGudJe5ZQR4Zg5WlilF5qN9n1YdyTav/nxhbFf2zk9OTQpdScXQSuY/5hAz+KRLgwiROpePNwh3jj5tAhmC6qtRadplsZWpqHsotGNVTzRedIi09ET+fzwdMs3IXLaGKKRbuE5P4R6f5FSVeHYJyps=" Sep 07 17:47:12 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:12+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:47:12 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:12+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:13 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:13+01:00" level=debug msg="completed challenge" Sep 07 17:47:13 minidsp-shd go-librespot[7545]: time="2024-09-07T17:47:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:15 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:15 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 292. Sep 07 17:47:16 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:16 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:16 minidsp-shd go-librespot[7562]: Librespot-go daemon starting... Sep 07 17:47:16 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:16+01:00" level=info msg="generated new device id: 8a23a1e24460dc7763b70dcaff00821a61986b88" Sep 07 17:47:16 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:16+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:16 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:16+01:00" level=debug msg="obtained new client token: AABRG+T5MEs5nE3Elhqspq2pSs7WXaacipTBADJDaoOlMGFCpR+1fHFIny11yW32a8YchqXpUKS25tE5YmwNqNp8L4ZDCKJWdpwi23baJNMX9a0/oL5RqJ0DxKvWD1jiTqGpmmpmllAyXcuK1IAN0kFNGSs5eluAl9FAskDGFkg/u63L2X3UNRZYnT9CSMpuEUvOtaez/w9VBC4UcaC4a9bn17Vei3ZG3ZrXUxwKceooYQ+5gnrlI8JC1+Mh7Yg=" Sep 07 17:47:17 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:17+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:47:17 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:17+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:17 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:17+01:00" level=debug msg="completed challenge" Sep 07 17:47:17 minidsp-shd go-librespot[7562]: time="2024-09-07T17:47:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:18 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:18 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 293. Sep 07 17:47:20 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:20 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:20 minidsp-shd go-librespot[7578]: Librespot-go daemon starting... Sep 07 17:47:20 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:20+01:00" level=info msg="generated new device id: ca3fc0327e3aade2125a9a50eaa94d5a20cf4d18" Sep 07 17:47:20 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:20+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:21 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:21+01:00" level=debug msg="obtained new client token: AADiSCMHqqbIeIPZFKr5aKXxjLc/uh//ZA9IQ0Bz65DBA17YJkTq7PK8kTU2xFIR2xK7RAnfsIrRyabvMp3p1Tzq96momAhUH90tV48gZzTrfHweZtPFY4haOsBPzBypQbVBm8V4MudB6H+As8nQiiJ3acubIxb3sLCN4nlnBWQEAxeTes5g7uNUWumaj9jJsJjEv+uk0zzqgtQqYaNRkOp/rQQIUV4isl7IuY1ZKViT2PZUMM1Oti2PL/8W" Sep 07 17:47:21 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:21 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:21+01:00" level=debug msg="new websocket client" Sep 07 17:47:21 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket established Sep 07 17:47:21 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:21+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:47:21 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:21+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:21 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:21+01:00" level=debug msg="completed challenge" Sep 07 17:47:21 minidsp-shd go-librespot[7578]: time="2024-09-07T17:47:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:21 minidsp-shd volumio[713]: info: Connection to go-librespot Websocket closed Sep 07 17:47:24 minidsp-shd volumio[713]: info: Getting Spotify volume Sep 07 17:47:24 minidsp-shd volumio[713]: (node:713) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:24 minidsp-shd volumio[713]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 17:47:24 minidsp-shd volumio[713]: (node:713) 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: 91) Sep 07 17:47:24 minidsp-shd volumio[713]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 17:47:24 minidsp-shd volumio[713]: info: CoreCommandRouter::volumioGetState Sep 07 17:47:24 minidsp-shd volumio[713]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 17:47:24 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:24 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 294. Sep 07 17:47:25 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:25 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:25 minidsp-shd go-librespot[7596]: Librespot-go daemon starting... Sep 07 17:47:25 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:25+01:00" level=info msg="generated new device id: 18e7eb832417371450154a712e06284b9554e474" Sep 07 17:47:25 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:25+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:25 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:25+01:00" level=debug msg="obtained new client token: AAAdA0BarEawRq5s3gj3PLcIRKX0QPMohYni6rj9NnQknijnXmil61qmZ0j/VqvMSrhbXcSVk0G6Y2voRxCuU9sKzoiku/+TZu7J/uuvEBvfniMJxRR45YvDc4Ydb4bZZJHaMy3j0dybTszQvflWZwX+mY9JNbtXbTmZx4+SHMaSqWVBw5i7UPdbRbVlqllZwpv/VCK17IFj9Vvdfn9AvOZ+yLbbkq0EcRq+yRevJkMgGh0Nk4+vLiRH/KhWU+o=" Sep 07 17:47:25 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:25+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 17:47:25 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:25+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:26 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:26+01:00" level=debug msg="completed challenge" Sep 07 17:47:26 minidsp-shd go-librespot[7596]: time="2024-09-07T17:47:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:27 minidsp-shd volumio[713]: info: Initializing connection to go-librespot Websocket Sep 07 17:47:27 minidsp-shd volumio[713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 17:47:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 17:47:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 295. Sep 07 17:47:29 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 17:47:29 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 17:47:29 minidsp-shd go-librespot[7614]: Librespot-go daemon starting... Sep 07 17:47:29 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:29+01:00" level=info msg="generated new device id: b9712aa72812749df7835ea50c063dac96a3e789" Sep 07 17:47:29 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:29+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 17:47:29 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:29+01:00" level=debug msg="obtained new client token: AAAg5aOxd0uLJ5Kbr4nDsKd4gjmqTFnq5rQwanKRV8F5c3qvMbQFtnVQp+iBCt1vdlzbAF7VF+aXC3fDravhem3WknDCqMwqxZC91DUsuJMFXeuMzIHYAGzla+Vn7pm589JjMBO5s8jbOI6BvdzBlwX1PWspeGMykj/xt1BEOzbB4ybyoPqfVnPLsyKs52bAmWxVo2UBHzcWdyVDm3zaKUD35S7CsOfzEiOwSwlwB8dTQxIHlLk7xGmmft+YFWU=" Sep 07 17:47:29 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:29+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 17:47:29 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:29+01:00" level=debug msg="completed keyexchange" Sep 07 17:47:30 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:30+01:00" level=debug msg="completed challenge" Sep 07 17:47:30 minidsp-shd go-librespot[7614]: time="2024-09-07T17:47:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 17:47:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 17:47:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 17:47:30 minidsp-shd volumio[713]: Searching all installed plugins Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: , search Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 07 17:47:30 minidsp-shd volumio[713]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 07 17:47:30 minidsp-shd volumio[713]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Sep 07 17:47:30 minidsp-shd volumio[713]: info: [1725727650510] ControllerCalmRadio::searchCategories Sep 07 17:47:30 minidsp-shd volumio[713]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 17:47:30 minidsp-shd volumio[713]: TypeError: Cannot read property 'cats' of undefined Sep 07 17:47:30 minidsp-shd volumio[713]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Sep 07 17:47:30 minidsp-shd volumio[713]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Sep 07 17:47:30 minidsp-shd volumio[713]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Sep 07 17:47:30 minidsp-shd volumio[713]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Sep 07 17:47:30 minidsp-shd volumio[713]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Sep 07 17:47:30 minidsp-shd volumio[713]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Sep 07 17:47:30 minidsp-shd volumio[713]: at Socket.emit (events.js:400:28) Sep 07 17:47:30 minidsp-shd volumio[713]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Sep 07 17:47:30 minidsp-shd volumio[713]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 07 17:47:30 minidsp-shd volumio[713]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 17:47:31 minidsp-shd sudo[7633]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-07 17:46 Sep 07 17:47:31 minidsp-shd sudo[7633]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:00:28 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="29ccfe8a9cff19911db4b736879ac117"