-- Logs begin at Wed 2025-03-19 21:46:29 CST, end at Fri 2025-07-18 18:08:20 CST. -- Jul 18 18:07:01 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:01 volumio go-librespot[2218]: time="2025-07-18T18:07:01+08:00" level=debug msg="new websocket client" Jul 18 18:07:01 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:07:01 volumio go-librespot[2218]: time="2025-07-18T18:07:01+08:00" level=debug msg="obtained new client token: AABB0biq5eLykmCOFfg7YuHyPhcRx78LmQnDOjdf/JEqEWkaPBdYTQzc4s9510xY1/s9r2TX03s7OSw+MBgG/mc+Hi7FHKUCRl8Hb3Aw+ByBW7QnvbRlDSf4065av3Ix5sY09FZUH5jEqci5a7lnwGNAHEeXICEpD8d6hhkdftvkD+13N2tmE8x/fL9C0r62w+oS3Wn6HceGn9O+dyZo/nYXw+3plWyoSHJfiI9wgw/Ejru3W9EUNJkdO27fCA/NxA==" Jul 18 18:07:03 volumio go-librespot[2218]: time="2025-07-18T18:07:03+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]" Jul 18 18:07:03 volumio go-librespot[2218]: time="2025-07-18T18:07:03+08:00" level=debug msg="completed keyexchange" Jul 18 18:07:04 volumio go-librespot[2218]: time="2025-07-18T18:07:04+08:00" level=debug msg="completed challenge" Jul 18 18:07:04 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:07:04 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:07:04 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:07:04 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:07:04 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:07:05 volumio go-librespot[2218]: time="2025-07-18T18:07:05+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" Jul 18 18:07:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:07:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:07:05 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 18 18:07:05 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Jul 18 18:07:05 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 18 18:07:05 volumio volumio[864]: at Socket.emit (events.js:327:22) Jul 18 18:07:05 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 18:07:05 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 18:07:05 volumio volumio[864]: (node:864) 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: 14) Jul 18 18:07:05 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:07:08 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:08 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:07:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:07:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jul 18 18:07:08 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:07:08 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:07:08 volumio go-librespot[2227]: Librespot-go daemon starting... Jul 18 18:07:08 volumio go-librespot[2227]: time="2025-07-18T18:07:08+08:00" level=info msg="generated new device id: f0f9f78fa034990fca9a676604bc8f4cae5d6888" Jul 18 18:07:08 volumio go-librespot[2227]: time="2025-07-18T18:07:08+08:00" level=debug msg="stored credentials not found" Jul 18 18:07:09 volumio go-librespot[2227]: time="2025-07-18T18:07:09+08:00" level=debug msg="obtained new client token: AACWEYWOUPbvMJ63TdPR95ZREj8M3ScQI8ZuMFkk9yXtsApjnAvKBHsFQWYMx7wluB9fzPhFmGe1vADZ7B9q4EZ+9ABJhfO7ctEk/KvVqUBPpfYVK5y4drR+E8bHlUwb/ZPk+kyxIY2iJoQ9E0TPrIex3OGm8eREjlrmZBMzNlXj5u/34YT9jJcHAbpCsYmw7HFTDxn1m8OH2tD9bMq0QS4va21xhi/cFPcgUJDx9Qe0d8P9Sxg566pbJxOGRiKsXw==" Jul 18 18:07:11 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:11 volumio go-librespot[2227]: time="2025-07-18T18:07:11+08:00" level=debug msg="new websocket client" Jul 18 18:07:11 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:07:14 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:07:14 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:07:14 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:07:14 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:07:14 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:07:19 volumio go-librespot[2227]: time="2025-07-18T18:07:19+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]" Jul 18 18:07:22 volumio go-librespot[2227]: time="2025-07-18T18:07:22+08:00" level=debug msg="completed keyexchange" Jul 18 18:07:22 volumio go-librespot[2227]: time="2025-07-18T18:07:22+08:00" level=debug msg="completed challenge" Jul 18 18:07:23 volumio go-librespot[2227]: time="2025-07-18T18:07:23+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" Jul 18 18:07:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:07:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:07:23 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 18 18:07:23 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Jul 18 18:07:23 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 18 18:07:23 volumio volumio[864]: at Socket.emit (events.js:327:22) Jul 18 18:07:23 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 18:07:23 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 18:07:23 volumio volumio[864]: (node:864) 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: 15) Jul 18 18:07:23 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:07:26 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:26 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:07:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:07:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jul 18 18:07:26 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:07:26 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:07:26 volumio go-librespot[2236]: Librespot-go daemon starting... Jul 18 18:07:26 volumio go-librespot[2236]: time="2025-07-18T18:07:26+08:00" level=info msg="generated new device id: 877c3e3b4ce311eeaad1cb4f8526252c84ee41ba" Jul 18 18:07:26 volumio go-librespot[2236]: time="2025-07-18T18:07:26+08:00" level=debug msg="stored credentials not found" Jul 18 18:07:27 volumio go-librespot[2236]: time="2025-07-18T18:07:27+08:00" level=debug msg="obtained new client token: AADN2XSiHKgWrryXvHDrnYBezDGKKIL3P6Bebf9zSY+7BZ1b4gvgdNp4RFHv3r8YSbS0QJq4HN9shMaCXhNBfsm2Xtx1cC802wZm2zM2VTi9rKP+C4L4i8tfRm7wBgJScqpVH90zZzOrcadnIv3ktESyuSUVohtyhH5bHF9Vfs1keX88aB0QhGNH5G5uUkSokXu2fp3ryI2Lrxg6e97ekh9SYc+Z5mnmUifXApDMryz0bdwHQdxdBpdE9uPMCJUyYA==" Jul 18 18:07:29 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:29 volumio go-librespot[2236]: time="2025-07-18T18:07:29+08:00" level=debug msg="new websocket client" Jul 18 18:07:29 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:07:29 volumio go-librespot[2236]: time="2025-07-18T18:07:29+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]" Jul 18 18:07:30 volumio go-librespot[2236]: time="2025-07-18T18:07:30+08:00" level=debug msg="completed keyexchange" Jul 18 18:07:31 volumio go-librespot[2236]: time="2025-07-18T18:07:31+08:00" level=debug msg="completed challenge" Jul 18 18:07:31 volumio go-librespot[2236]: time="2025-07-18T18:07:31+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" Jul 18 18:07:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:07:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:07:31 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:07:32 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:07:32 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:07:32 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 18 18:07:32 volumio volumio[864]: (node:864) 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: 16) Jul 18 18:07:32 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:07:32 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:07:32 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:07:32 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:07:34 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:34 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:07:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:07:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jul 18 18:07:34 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:07:34 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:07:34 volumio go-librespot[2245]: Librespot-go daemon starting... Jul 18 18:07:34 volumio go-librespot[2245]: time="2025-07-18T18:07:34+08:00" level=info msg="generated new device id: 6da58c7c7bc051b086085c1fdb7f90e0252c8346" Jul 18 18:07:34 volumio go-librespot[2245]: time="2025-07-18T18:07:34+08:00" level=debug msg="stored credentials not found" Jul 18 18:07:36 volumio go-librespot[2245]: time="2025-07-18T18:07:36+08:00" level=debug msg="obtained new client token: AAC2JXvibkFmAm09pxbVuV0UlkyLz9y77mBuQ6hnmgx2d/GpOQRuvY+8imkuHLGp4gpsDPfgdWl0z0izM2qZUhkpA/Xu6W1K0uo7jMnu1JYsPpSsPMhZ7fBG0PAVGD8H/khZAT97lV9kMev8iXcqRqDzqZBlxhwpNUaRDKX9tV8mV1E11mL6HKuENGZyKVNXXH3HmGLyx1mItrKMnk5QBh5x3DoEXLbkBKYqXwL43RjYtUW+Tceul62bpGLzuvZ4bQ==" Jul 18 18:07:37 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:37 volumio go-librespot[2245]: time="2025-07-18T18:07:37+08:00" level=debug msg="new websocket client" Jul 18 18:07:37 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:07:39 volumio go-librespot[2245]: time="2025-07-18T18:07:39+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]" Jul 18 18:07:40 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:07:40 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:07:40 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:07:40 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:07:40 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:07:42 volumio go-librespot[2245]: time="2025-07-18T18:07:42+08:00" level=debug msg="completed keyexchange" Jul 18 18:07:42 volumio go-librespot[2245]: time="2025-07-18T18:07:42+08:00" level=debug msg="completed challenge" Jul 18 18:07:43 volumio go-librespot[2245]: time="2025-07-18T18:07:43+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" Jul 18 18:07:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:07:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:07:43 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 18 18:07:43 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Jul 18 18:07:43 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 18 18:07:43 volumio volumio[864]: at Socket.emit (events.js:327:22) Jul 18 18:07:43 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 18:07:43 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 18:07:43 volumio volumio[864]: (node:864) 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: 17) Jul 18 18:07:43 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:07:46 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:46 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:07:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:07:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jul 18 18:07:46 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:07:46 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:07:46 volumio go-librespot[2253]: Librespot-go daemon starting... Jul 18 18:07:46 volumio go-librespot[2253]: time="2025-07-18T18:07:46+08:00" level=info msg="generated new device id: 9b964285cd43ceb148e69641cf9cf1acf4b4e51e" Jul 18 18:07:46 volumio go-librespot[2253]: time="2025-07-18T18:07:46+08:00" level=debug msg="stored credentials not found" Jul 18 18:07:48 volumio go-librespot[2253]: time="2025-07-18T18:07:48+08:00" level=debug msg="obtained new client token: AAAnTgJFLgnFtPI+Kkm/vAeEKXpvXgg6pWtJBhHsuQ/FcGFkcK18Md3BC2nshvpE7XoOnde7spEiMJpw+4Nio+Pr4/Wk6UOa7VVT61qt1QKg6jQQCNWl0C31XMrfnlQiBNxAj2/ADZU0BGuKnhO4TsQfr6G/lcy/0SWFU/RG6a+CZnlDWKeDgOQ+jOrzj9Q14yf4T7S6XLZNjUfhVXGwnafWIuFYFcvn0C/9gN4lU1o8r5AGJzrvA9FkEv9vDYA=" Jul 18 18:07:49 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:49 volumio go-librespot[2253]: time="2025-07-18T18:07:49+08:00" level=debug msg="new websocket client" Jul 18 18:07:49 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:07:51 volumio go-librespot[2253]: time="2025-07-18T18:07:51+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]" Jul 18 18:07:52 volumio go-librespot[2253]: time="2025-07-18T18:07:52+08:00" level=debug msg="completed keyexchange" Jul 18 18:07:52 volumio go-librespot[2253]: time="2025-07-18T18:07:52+08:00" level=debug msg="completed challenge" Jul 18 18:07:52 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:07:52 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:07:52 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:07:52 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:07:52 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:07:52 volumio go-librespot[2253]: time="2025-07-18T18:07:52+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" Jul 18 18:07:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:07:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:07:52 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 18 18:07:52 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Jul 18 18:07:52 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 18 18:07:52 volumio volumio[864]: at Socket.emit (events.js:327:22) Jul 18 18:07:52 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 18:07:52 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 18:07:52 volumio volumio[864]: (node:864) 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: 18) Jul 18 18:07:52 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:07:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:07:55 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jul 18 18:07:55 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:07:55 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:07:55 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:07:55 volumio go-librespot[2268]: Librespot-go daemon starting... Jul 18 18:07:55 volumio go-librespot[2268]: time="2025-07-18T18:07:55+08:00" level=info msg="generated new device id: 71654ecd0a3d55ecf1c4323da26a63331ebd9daa" Jul 18 18:07:55 volumio go-librespot[2268]: time="2025-07-18T18:07:55+08:00" level=debug msg="stored credentials not found" Jul 18 18:07:57 volumio go-librespot[2268]: time="2025-07-18T18:07:57+08:00" level=debug msg="obtained new client token: AACTCdn0dzb0ER44wxozxOMinL7ao3NJGQT1PEZqYx2XRE5uha/hdxXCheBG8k8Ko3GujpE2TJbp0moj0LsTZV3qjyy+y4P1g5Ww5eelQ3iRJ7Q9qf2QgH3OHvTzljUnq5MEcy8BKTOIxJMYiJdNIMX4rqyZBsAsAFyWJPx3NhjkTGKs822CCDgzA2UTvgaLViGW4HhezuD2sVWD/wYJ0hATbvUmfdenGS07cwQKs1ywtVAsPctfRrr1lp9OMtlGow==" Jul 18 18:07:58 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:07:58 volumio go-librespot[2268]: time="2025-07-18T18:07:58+08:00" level=debug msg="new websocket client" Jul 18 18:07:58 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:07:59 volumio go-librespot[2268]: time="2025-07-18T18:07: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 18 18:07:59 volumio go-librespot[2268]: time="2025-07-18T18:07:59+08:00" level=debug msg="completed keyexchange" Jul 18 18:08:00 volumio go-librespot[2268]: time="2025-07-18T18:08:00+08:00" level=debug msg="completed challenge" Jul 18 18:08:00 volumio go-librespot[2268]: time="2025-07-18T18:08:00+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" Jul 18 18:08:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:08:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:08:00 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:08:01 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:08:01 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:08:01 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 18 18:08:01 volumio volumio[864]: (node:864) 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: 19) Jul 18 18:08:01 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:08:01 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:08:01 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:08:01 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:08:03 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:08:03 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:08:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:08:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jul 18 18:08:03 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:08:03 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:08:03 volumio go-librespot[2320]: Librespot-go daemon starting... Jul 18 18:08:03 volumio go-librespot[2320]: time="2025-07-18T18:08:03+08:00" level=info msg="generated new device id: 49d3df15791c68510c8c115e525298b282156889" Jul 18 18:08:03 volumio go-librespot[2320]: time="2025-07-18T18:08:03+08:00" level=debug msg="stored credentials not found" Jul 18 18:08:05 volumio go-librespot[2320]: time="2025-07-18T18:08:05+08:00" level=debug msg="obtained new client token: AAA9etvZ2c3UkShNvEtHDHPo5hyvWbWibALdaCZsMkStg4c12StpUGcH9re+zoUvtIieAvOxULuw6eNTf1SVHwGRXMM2EGrkOjpROh3RtDcH3GJm0TIFcLMN/7NMzyrtFUEhRqoLzSbm09HcI9F+Cfvbf9j37jocqpau3/FMa6r4BylC7UZojK/4K5TnhfcK6/5XFbk+Bn/ZsZ2VX1Y2wNtPYdR6HRR/r3HqgM2yMKRihVxqiPVkXVavvr8l2LAreQ==" Jul 18 18:08:06 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:08:06 volumio go-librespot[2320]: time="2025-07-18T18:08:06+08:00" level=debug msg="new websocket client" Jul 18 18:08:06 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:08:06 volumio go-librespot[2320]: time="2025-07-18T18:08:06+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]" Jul 18 18:08:07 volumio go-librespot[2320]: time="2025-07-18T18:08:07+08:00" level=debug msg="completed keyexchange" Jul 18 18:08:07 volumio go-librespot[2320]: time="2025-07-18T18:08:07+08:00" level=debug msg="completed challenge" Jul 18 18:08:08 volumio go-librespot[2320]: time="2025-07-18T18:08:08+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" Jul 18 18:08:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:08:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:08:08 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:08:09 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:08:09 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:08:09 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 18 18:08:09 volumio volumio[864]: (node:864) 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: 20) Jul 18 18:08:09 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:08:09 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:08:09 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:08:09 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:08:11 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:08:11 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:08:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:08:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jul 18 18:08:11 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:08:11 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:08:11 volumio go-librespot[2329]: Librespot-go daemon starting... Jul 18 18:08:11 volumio go-librespot[2329]: time="2025-07-18T18:08:11+08:00" level=info msg="generated new device id: 066c9973b05881e4628aed00038cd57e23310c66" Jul 18 18:08:11 volumio go-librespot[2329]: time="2025-07-18T18:08:11+08:00" level=debug msg="stored credentials not found" Jul 18 18:08:13 volumio go-librespot[2329]: time="2025-07-18T18:08:13+08:00" level=debug msg="obtained new client token: AAAGDUt8gijfmJfahA0TK6barE67T5RYYygvGxfVZ2AykJVuvMb/ugHTZn0U/cGCtHRnujybvky5FF/qD6PcQB4mqCD8zMhVgZeAkZgzaPvI+bTWfWSpX+8j5T6byVWEk1+X306wOr7WVFZtcu9Gi3JPrOi+f+GLNbCwdpNRZ3gVPuKxghvW3pVXfpVrRbYSF8gq/URc2fxCryINkvmIbq8NyrneUY4G22wnKYMIzUtd6stDt4vHRHE5Y2rAMUTkhA==" Jul 18 18:08:14 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Jul 18 18:08:14 volumio go-librespot[2329]: time="2025-07-18T18:08:14+08:00" level=debug msg="new websocket client" Jul 18 18:08:14 volumio volumio[864]: info: Connection to go-librespot Websocket established Jul 18 18:08:14 volumio go-librespot[2329]: time="2025-07-18T18:08:14+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]" Jul 18 18:08:16 volumio go-librespot[2329]: time="2025-07-18T18:08:16+08:00" level=debug msg="completed keyexchange" Jul 18 18:08:16 volumio go-librespot[2329]: time="2025-07-18T18:08:16+08:00" level=debug msg="completed challenge" Jul 18 18:08:16 volumio go-librespot[2329]: time="2025-07-18T18:08: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" Jul 18 18:08:16 volumio volumio[864]: info: Connection to go-librespot Websocket closed Jul 18 18:08:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 18:08:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 18:08:17 volumio volumio[864]: info: Getting Spotify volume Jul 18 18:08:17 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 18:08:17 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 18 18:08:17 volumio volumio[864]: (node:864) 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: 21) Jul 18 18:08:17 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 18 18:08:17 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Jul 18 18:08:17 volumio volumio[864]: info: CorePlayQueue::getTrack 20 Jul 18 18:08:17 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 18 18:08:19 volumio volumio[864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 18:08:19 volumio volumio[864]: Error: connect ETIMEDOUT 31.13.94.10:80 Jul 18 18:08:19 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Jul 18 18:08:19 volumio volumio[864]: errno: -110, Jul 18 18:08:19 volumio volumio[864]: code: 'ETIMEDOUT', Jul 18 18:08:19 volumio volumio[864]: syscall: 'connect', Jul 18 18:08:19 volumio volumio[864]: address: '31.13.94.10', Jul 18 18:08:19 volumio volumio[864]: port: 80 Jul 18 18:08:19 volumio volumio[864]: } Jul 18 18:08:19 volumio volumio[864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 18:08:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 18:08:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jul 18 18:08:20 volumio systemd[1]: Stopped go-librespot Daemon. Jul 18 18:08:20 volumio systemd[1]: Started go-librespot Daemon. Jul 18 18:08:20 volumio go-librespot[2346]: Librespot-go daemon starting... Jul 18 18:08:20 volumio go-librespot[2346]: time="2025-07-18T18:08:20+08:00" level=info msg="generated new device id: 9214d236dcb5cd2ae8c4bea983e489fd59ead3f2" Jul 18 18:08:20 volumio go-librespot[2346]: time="2025-07-18T18:08:20+08:00" level=debug msg="stored credentials not found" Jul 18 18:08:20 volumio sudo[2354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 18:07 Jul 18 18:08:20 volumio sudo[2354]: 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"