-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Fri 2024-04-26 12:58:18 CST. -- Apr 26 12:57:00 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:00 volumio go-librespot[4646]: time="2024-04-26T12:57:00+08:00" level=debug msg="new websocket client" Apr 26 12:57:00 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:00 volumio go-librespot[4646]: time="2024-04-26T12:57:00+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 12:57:01 volumio go-librespot[4646]: time="2024-04-26T12:57:01+08:00" level=debug msg="completed keyexchange" Apr 26 12:57:01 volumio go-librespot[4646]: time="2024-04-26T12:57:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed solving challenge: failed login: BadCredentials" Apr 26 12:57:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:57:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:57:01 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:57:03 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:03 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:03 volumio volumio[833]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 12:57:03 volumio volumio[833]: (node:833) 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: 39) Apr 26 12:57:03 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:03 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:03 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:04 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:04 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:57:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 193. Apr 26 12:57:05 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:57:05 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:57:05 volumio go-librespot[4656]: Librespot-go daemon starting... Apr 26 12:57:05 volumio go-librespot[4656]: time="2024-04-26T12:57:05+08:00" level=info msg="generated new device id: c4086b353ea99d8ac2fee69324771d4a2912270a" Apr 26 12:57:05 volumio go-librespot[4656]: time="2024-04-26T12:57:05+08:00" level=debug msg="stored credentials not found" Apr 26 12:57:06 volumio go-librespot[4656]: time="2024-04-26T12:57:06+08:00" level=debug msg="obtained new client token: AABvvbjz/wo+iG+Vy2HkI2MP6OmK4q/zXL4sVBf3low//+ytho1cD5+raPovBAn2aOj2HK++QPJ2SKqmv80N5Qx+NjviMMUPV+huCfWM05imj9Rn4x3rtbn1krxJ0cDMljXvPK7pGzSJTE/Cfq8ePvdkmDHR4of8ADrruSWG1TcLekMmmhFiUi+7sbWA/1G2LSdktLkHeXjZbEk3M43uSM5hSSbND91+hgqAvGwmS/ItcOZ0LZwelChmv1agDEg=" Apr 26 12:57:07 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:07 volumio go-librespot[4656]: time="2024-04-26T12:57:07+08:00" level=debug msg="new websocket client" Apr 26 12:57:07 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:07 volumio go-librespot[4656]: time="2024-04-26T12:57:07+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 12:57:08 volumio go-librespot[4656]: time="2024-04-26T12:57:08+08:00" level=debug msg="completed keyexchange" Apr 26 12:57:09 volumio go-librespot[4656]: time="2024-04-26T12:57:09+08:00" level=debug msg="completed challenge" Apr 26 12:57:09 volumio go-librespot[4656]: time="2024-04-26T12:57:09+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Apr 26 12:57:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:57:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:57:09 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:57:10 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:10 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:10 volumio volumio[833]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 12:57:10 volumio volumio[833]: (node:833) 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: 40) Apr 26 12:57:10 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:10 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:10 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:12 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:12 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:57:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 194. Apr 26 12:57:12 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:57:12 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:57:12 volumio go-librespot[4665]: Librespot-go daemon starting... Apr 26 12:57:12 volumio go-librespot[4665]: time="2024-04-26T12:57:12+08:00" level=info msg="generated new device id: 69602099d828a92ac5ea6639d7f692fe8ad7583e" Apr 26 12:57:12 volumio go-librespot[4665]: time="2024-04-26T12:57:12+08:00" level=debug msg="stored credentials not found" Apr 26 12:57:14 volumio go-librespot[4665]: time="2024-04-26T12:57:14+08:00" level=debug msg="obtained new client token: AACAP0Gwx87zhyzUj2+/mIUrpYhmvdWPxF0asytLdRyl/hAXbVAc9ZRUtQreFCzzY6nikNfM9wnbEpiJrCLQpBKc5ugaPcGvAKFqhtKSv5JdcEpOZyTtIprTtrPmDo6a5TUIzd6ZJYSs1dRBLHEaXsheJy1EBaplZr6Il0D+sxlspthke5mhn8wir3Si8zry09SPGcOXFdB8EHUcjYb97nsObI81XIOxifaOAiOu4EcqHD/Al3l0jh+8MSEcJCw=" Apr 26 12:57:15 volumio go-librespot[4665]: time="2024-04-26T12:57:15+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 26 12:57:15 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:15 volumio go-librespot[4665]: time="2024-04-26T12:57:15+08:00" level=debug msg="new websocket client" Apr 26 12:57:15 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:16 volumio go-librespot[4665]: time="2024-04-26T12:57:16+08:00" level=debug msg="completed keyexchange" Apr 26 12:57:16 volumio go-librespot[4665]: time="2024-04-26T12:57:16+08:00" level=debug msg="completed challenge" Apr 26 12:57:16 volumio go-librespot[4665]: time="2024-04-26T12:57:16+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Apr 26 12:57:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:57:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:57:16 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:57:18 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:18 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:18 volumio volumio[833]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 12:57:18 volumio volumio[833]: (node:833) 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: 41) Apr 26 12:57:18 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:18 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:18 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:19 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:19 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:57:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 195. Apr 26 12:57:19 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:57:19 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:57:19 volumio go-librespot[4673]: Librespot-go daemon starting... Apr 26 12:57:19 volumio go-librespot[4673]: time="2024-04-26T12:57:19+08:00" level=info msg="generated new device id: 951557b98956efa67518ce6c89696062f929844f" Apr 26 12:57:19 volumio go-librespot[4673]: time="2024-04-26T12:57:19+08:00" level=debug msg="stored credentials not found" Apr 26 12:57:22 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:22 volumio go-librespot[4673]: time="2024-04-26T12:57:22+08:00" level=debug msg="new websocket client" Apr 26 12:57:22 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:25 volumio go-librespot[4673]: time="2024-04-26T12:57:25+08:00" level=debug msg="obtained new client token: AADXoe2lhESegFjnvWKsPvf/VyQ9mghQYtivwJAV/q/Yftd+s8wVSm4vi3IEDb/pzE/l1JwqcOeIWbSHqtdVm8P3giBzfaD/CzJzpYvFWlJiJo3aB9kwiYAG2n5KCn05cR4i0BULOh7FVIDCeYXiLCdk6GXnhza03nmUXJA47jOY1tednSiT6xy+Vov1HBTLRJ8iJZBg9bty85hdInqo48dBT2HZSxaOLrdHGIMeSvGuqk3FaWUOyT7DJWuvlj8=" Apr 26 12:57:25 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:25 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:25 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:25 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:26 volumio go-librespot[4673]: time="2024-04-26T12:57:26+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 12:57:27 volumio go-librespot[4673]: time="2024-04-26T12:57:27+08:00" level=debug msg="completed keyexchange" Apr 26 12:57:27 volumio go-librespot[4673]: time="2024-04-26T12:57:27+08:00" level=debug msg="completed challenge" Apr 26 12:57:28 volumio go-librespot[4673]: time="2024-04-26T12:57:28+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Apr 26 12:57:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:57:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:57:28 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 26 12:57:28 volumio volumio[833]: at connResetException (internal/errors.js:607:14) Apr 26 12:57:28 volumio volumio[833]: at Socket.socketOnEnd (_http_client.js:493:23) Apr 26 12:57:28 volumio volumio[833]: at Socket.emit (events.js:327:22) Apr 26 12:57:28 volumio volumio[833]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 26 12:57:28 volumio volumio[833]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 26 12:57:28 volumio volumio[833]: (node:833) 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: 42) Apr 26 12:57:28 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:57:31 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:31 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:57:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 196. Apr 26 12:57:31 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:57:31 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:57:31 volumio go-librespot[4683]: Librespot-go daemon starting... Apr 26 12:57:31 volumio go-librespot[4683]: time="2024-04-26T12:57:31+08:00" level=info msg="generated new device id: b23eda1d84b2cbde61aed7bcf2826ae15a949750" Apr 26 12:57:31 volumio go-librespot[4683]: time="2024-04-26T12:57:31+08:00" level=debug msg="stored credentials not found" Apr 26 12:57:32 volumio go-librespot[4683]: time="2024-04-26T12:57:32+08:00" level=debug msg="obtained new client token: AAC383yxz3Ad6FRETZiB+gFjjfY0SF55ivY83wSaEh00VF/nm0I2k8VUXnZUmvoS6F2nzwTwh6IccYEJ2smakisclmAYkvZQwDTilfJofmIyVO+57GxX4nxW/RWET2qi2uLBa52KWDAaHDf/zjWQRxhQbwcQoyhvGPUaCK3Xs+ZBz/5yNDMTwn5buJY9DXcCChNWowev0J7Ml3f/IjjUoQu8Hm/2tHcvGH/WBTqnRTlWx/INVDMWlySnZcTGcbI=" Apr 26 12:57:34 volumio go-librespot[4683]: time="2024-04-26T12:57:34+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 26 12:57:34 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:34 volumio go-librespot[4683]: time="2024-04-26T12:57:34+08:00" level=debug msg="new websocket client" Apr 26 12:57:34 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:34 volumio go-librespot[4683]: time="2024-04-26T12:57:34+08:00" level=debug msg="completed keyexchange" Apr 26 12:57:34 volumio go-librespot[4683]: time="2024-04-26T12:57:34+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed solving challenge: failed login: BadCredentials" Apr 26 12:57:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:57:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:57:34 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:57:37 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:37 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:37 volumio volumio[833]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 26 12:57:37 volumio volumio[833]: (node:833) 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: 43) Apr 26 12:57:37 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:37 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:37 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:37 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:37 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:57:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 197. Apr 26 12:57:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:57:37 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:57:37 volumio go-librespot[4732]: Librespot-go daemon starting... Apr 26 12:57:37 volumio go-librespot[4732]: time="2024-04-26T12:57:37+08:00" level=info msg="generated new device id: ddb6edfa6cdd01be23ab5637c9fb5a948150ed4e" Apr 26 12:57:37 volumio go-librespot[4732]: time="2024-04-26T12:57:37+08:00" level=debug msg="stored credentials not found" Apr 26 12:57:39 volumio go-librespot[4732]: time="2024-04-26T12:57:39+08:00" level=debug msg="obtained new client token: AACW0vnMC1cJsxmAU1STXNaEVPRyabLCzgiGQwfjpa9Y1Ny5uxoQMrLtgvQeQVJNoILb6Lk7KQw+6I2HvuCtBqlhJT8TjcuxC7vJE97uAK/nrNyJbmOLzx29amdOrbOiYaJAFe4VXt6tKiDGlVILJvYWo4UM5Y7ALMj2s7+Uv1Se4rbp7YbgUfCTs823ev1r88XSRpJnkA7YgYe6zzsP2sMwL4jSDF0q90UrirSrFYlMlExhQP41XYC4xg==" Apr 26 12:57:40 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:40 volumio go-librespot[4732]: time="2024-04-26T12:57:40+08:00" level=debug msg="new websocket client" Apr 26 12:57:40 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:42 volumio go-librespot[4732]: time="2024-04-26T12:57:42+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 12:57:43 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:43 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:43 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:43 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:45 volumio go-librespot[4732]: time="2024-04-26T12:57:45+08:00" level=debug msg="completed keyexchange" Apr 26 12:57:45 volumio go-librespot[4732]: time="2024-04-26T12:57:45+08:00" level=debug msg="completed challenge" Apr 26 12:57:46 volumio go-librespot[4732]: time="2024-04-26T12:57:46+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Apr 26 12:57:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:57:46 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 26 12:57:46 volumio volumio[833]: at connResetException (internal/errors.js:607:14) Apr 26 12:57:46 volumio volumio[833]: at Socket.socketOnEnd (_http_client.js:493:23) Apr 26 12:57:46 volumio volumio[833]: at Socket.emit (events.js:327:22) Apr 26 12:57:46 volumio volumio[833]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 26 12:57:46 volumio volumio[833]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 26 12:57:46 volumio volumio[833]: (node:833) 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: 44) Apr 26 12:57:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:57:46 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:57:49 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:49 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:57:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:57:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 198. Apr 26 12:57:49 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:57:49 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:57:49 volumio go-librespot[4740]: Librespot-go daemon starting... Apr 26 12:57:49 volumio go-librespot[4740]: time="2024-04-26T12:57:49+08:00" level=info msg="generated new device id: 19f6117d4cc6cad52efd2644eca2577ef60f906d" Apr 26 12:57:49 volumio go-librespot[4740]: time="2024-04-26T12:57:49+08:00" level=debug msg="stored credentials not found" Apr 26 12:57:52 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:57:52 volumio go-librespot[4740]: time="2024-04-26T12:57:52+08:00" level=debug msg="new websocket client" Apr 26 12:57:52 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:57:55 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:57:55 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:57:55 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:57:55 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:57:57 volumio go-librespot[4740]: time="2024-04-26T12:57:57+08:00" level=debug msg="obtained new client token: AADbkQJ/t5DmJdJdThen7uggdj/RSgDHR9/VajZJoP9J7rvnv/mBoS14C66X5GUCN2gNktosqdXJJLkhZNZhwJQXmGIYI4km9D2whfcLEIeIz/Lp6KuJn6q0Q5EofAa7oXEyWwOpVXknR31l8qK+LuN9I5i00OlylKWSNWzndChzPAkaFgMZCY9Yx48hp3RJ93VGJ6VdAfjnlUjacwM5WUCfNjdiKoTdCTAT+m4pBRDh3ur926sF53p4JP7WL2Q=" Apr 26 12:57:59 volumio go-librespot[4740]: time="2024-04-26T12:57:59+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 12:58:00 volumio go-librespot[4740]: time="2024-04-26T12:58:00+08:00" level=debug msg="completed keyexchange" Apr 26 12:58:00 volumio go-librespot[4740]: time="2024-04-26T12:58:00+08:00" level=debug msg="completed challenge" Apr 26 12:58:01 volumio go-librespot[4740]: time="2024-04-26T12:58:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Apr 26 12:58:01 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 26 12:58:01 volumio volumio[833]: at connResetException (internal/errors.js:607:14) Apr 26 12:58:01 volumio volumio[833]: at Socket.socketOnEnd (_http_client.js:493:23) Apr 26 12:58:01 volumio volumio[833]: at Socket.emit (events.js:327:22) Apr 26 12:58:01 volumio volumio[833]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 26 12:58:01 volumio volumio[833]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 26 12:58:01 volumio volumio[833]: (node:833) 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: 45) Apr 26 12:58:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:58:01 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:58:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:58:04 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:58:04 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:58:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:58:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 199. Apr 26 12:58:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:58:04 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:58:04 volumio go-librespot[4753]: Librespot-go daemon starting... Apr 26 12:58:04 volumio go-librespot[4753]: time="2024-04-26T12:58:04+08:00" level=info msg="generated new device id: a15a988bb81ab58b720e55308ef75084b2a9fde9" Apr 26 12:58:04 volumio go-librespot[4753]: time="2024-04-26T12:58:04+08:00" level=debug msg="stored credentials not found" Apr 26 12:58:06 volumio go-librespot[4753]: time="2024-04-26T12:58:06+08:00" level=debug msg="obtained new client token: AABb+eqOqw5NltGYVZs6dzTu/47hWBtA4KeTDbqbJ2MKmBQY3p02LLBDWSOPj+1eedOBRjk5U9sQKz+VzJayxHCVEIBhLX/j2CUlBdHEE0mLYFpio9xklZ9UN8qCaZoVTATKGVRWgyp5ZXb0w1HUN2pgN6fQ0L9uoQkGBiz03vGmd6WF6kDGc9FWOXUCRaAzdIfu3G730YZTjcgMhfKxbqRP9jEV0MwxgRIKMKteLf79ralRHCFwHwQjjGaT4A0=" Apr 26 12:58:07 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:58:07 volumio go-librespot[4753]: time="2024-04-26T12:58:07+08:00" level=debug msg="new websocket client" Apr 26 12:58:07 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:58:09 volumio go-librespot[4753]: time="2024-04-26T12:58:09+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 26 12:58:09 volumio go-librespot[4753]: time="2024-04-26T12:58:09+08:00" level=debug msg="completed keyexchange" Apr 26 12:58:10 volumio volumio[833]: info: Getting Spotify volume Apr 26 12:58:10 volumio volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Apr 26 12:58:10 volumio volumio[833]: info: CoreCommandRouter::volumioGetState Apr 26 12:58:10 volumio volumio[833]: info: CorePlayQueue::getTrack 0 Apr 26 12:58:10 volumio go-librespot[4753]: time="2024-04-26T12:58:10+08:00" level=debug msg="completed challenge" Apr 26 12:58:10 volumio go-librespot[4753]: time="2024-04-26T12:58:10+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Apr 26 12:58:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 26 12:58:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 26 12:58:10 volumio volumio[833]: (node:833) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 26 12:58:10 volumio volumio[833]: at connResetException (internal/errors.js:607:14) Apr 26 12:58:10 volumio volumio[833]: at Socket.socketOnEnd (_http_client.js:493:23) Apr 26 12:58:10 volumio volumio[833]: at Socket.emit (events.js:327:22) Apr 26 12:58:10 volumio volumio[833]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 26 12:58:10 volumio volumio[833]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 26 12:58:10 volumio volumio[833]: (node:833) 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: 46) Apr 26 12:58:10 volumio volumio[833]: info: Connection to go-librespot Websocket closed Apr 26 12:58:13 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:58:13 volumio volumio[833]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 26 12:58:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 26 12:58:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 200. Apr 26 12:58:13 volumio systemd[1]: Stopped go-librespot Daemon. Apr 26 12:58:13 volumio systemd[1]: Started go-librespot Daemon. Apr 26 12:58:13 volumio go-librespot[4761]: Librespot-go daemon starting... Apr 26 12:58:13 volumio go-librespot[4761]: time="2024-04-26T12:58:13+08:00" level=info msg="generated new device id: 64e70ccf5ea2dc0c667403cec4e7129da1263ae2" Apr 26 12:58:13 volumio go-librespot[4761]: time="2024-04-26T12:58:13+08:00" level=debug msg="stored credentials not found" Apr 26 12:58:16 volumio volumio[833]: info: Initializing connection to go-librespot Websocket Apr 26 12:58:16 volumio go-librespot[4761]: time="2024-04-26T12:58:16+08:00" level=debug msg="new websocket client" Apr 26 12:58:16 volumio volumio[833]: info: Connection to go-librespot Websocket established Apr 26 12:58:17 volumio go-librespot[4761]: time="2024-04-26T12:58:17+08:00" level=debug msg="obtained new client token: AABLtAJB5q/1UfvbU9AcIe7S37YdrpZZEXT5G1jY49ktzwwSJFR72w4+Tt1agvUYKAkKOVW5TM2TxviYctv2tkHIxYm9XLcfKJ09tzpxcWiuQW9qhpgKqSf/+RvVHY+Xzaj7GLO7AtiqO1IfFQbARN6MeEu14YibZEmoPFDJea5l8IkveV1D1jiN1nhX7utXjBbCywfsfCKNu7865Sk0Pic8K9bZZt6K+6eT4koB5K+NNdPInET8No5Nz7Y5A1w=" Apr 26 12:58:17 volumio volumio[833]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 26 12:58:17 volumio volumio[833]: Error: connect ETIMEDOUT 199.59.150.12:80 Apr 26 12:58:17 volumio volumio[833]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Apr 26 12:58:17 volumio volumio[833]: errno: -110, Apr 26 12:58:17 volumio volumio[833]: code: 'ETIMEDOUT', Apr 26 12:58:17 volumio volumio[833]: syscall: 'connect', Apr 26 12:58:17 volumio volumio[833]: address: '199.59.150.12', Apr 26 12:58:17 volumio volumio[833]: port: 80 Apr 26 12:58:17 volumio volumio[833]: } Apr 26 12:58:17 volumio volumio[833]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 26 12:58:18 volumio sudo[4778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-26 12:57 Apr 26 12:58:18 volumio sudo[4778]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"