-- Logs begin at Thu 2019-02-14 10:11:58 GMT, end at Fri 2025-07-18 21:43:23 BST. --
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:00 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:00 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Jul 18 21:42:00 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:00 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:00 richdacvolumio go-librespot[8206]: Librespot-go daemon starting...
Jul 18 21:42:00 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:00+01:00" level=info msg="generated new device id: 2da17f6a8c498c51616361434fe3b1c39f6a1c1e"
Jul 18 21:42:00 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:00+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:01 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:01+01:00" level=debug msg="obtained new client token: AAA/89q7e6GFsdMS7mpU+1qdfJqP//zUdDgfoP5TlFWCY6sU5JYPB/ZzYSzjvrfdYr5CbD3Xa2yuwFCq10UbfuRB24eye/qsi8L6xuhR7mrP7uaeeRGECQjNu9OR6JNJOtCF/lfBnnz52GIzXI4s7cN4it/4MYW7D7Bq+DLJQ/GVfBa8s5HKz5qrZnvEuqxDP1cVrZV0i6fIk5LiKyzfwoYReT6mMy331jIzBK31l7+qYDzecUHGYYq+8relaA=="
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:01 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:01 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:01+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:02 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:02+01:00" level=debug msg="completed challenge"
Jul 18 21:42:02 richdacvolumio go-librespot[8206]: time="2025-07-18T21:42:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:42:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Jul 18 21:42:05 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:05 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:05 richdacvolumio go-librespot[8371]: Librespot-go daemon starting...
Jul 18 21:42:05 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:05+01:00" level=info msg="generated new device id: b221fbe50fc30cf979962d37cc441edb8dc22d5c"
Jul 18 21:42:05 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:05+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:06 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:06+01:00" level=debug msg="new websocket client"
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket established
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: Getting Spotify volume
Jul 18 21:42:09 richdacvolumio volumio[5899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:10+01:00" level=debug msg="obtained new client token: AAC0T0A0jn/bXwh38zPdP1h/dILHpk2wSg1rlCH8RoGbGE9/cOD933z9T2COjq7lEb8C1cdY7/8YwPKLz9ZN8lUW7iCXBbD253NZO6WQzpR1nKW4E27/Qm358wtG490gxW0zu03EGdDuK1s65B8C/bsgbiTQpr6h97+I2xw18+qPBGaiJpQIQkTxHdTgr/fQpcEG7WLQlPRypiZ+vTpfkDyxv8pFLngRW4wmpOe7jrtxLe99Fo2iS0gfvXc="
Jul 18 21:42:10 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:10+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:10 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42:10+01:00" level=debug msg="completed challenge"
Jul 18 21:42:10 richdacvolumio go-librespot[8371]: time="2025-07-18T21:42: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"
Jul 18 21:42:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:10 richdacvolumio volumio[5899]: (node:5899) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 18 21:42:10 richdacvolumio volumio[5899]: at connResetException (internal/errors.js:607:14)
Jul 18 21:42:10 richdacvolumio volumio[5899]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 18 21:42:10 richdacvolumio volumio[5899]: at Socket.emit (events.js:327:22)
Jul 18 21:42:10 richdacvolumio volumio[5899]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 18 21:42:10 richdacvolumio volumio[5899]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 18 21:42:10 richdacvolumio volumio[5899]: (node:5899) 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: 6)
Jul 18 21:42:10 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket closed
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:13 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Jul 18 21:42:14 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:14 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:14 richdacvolumio go-librespot[8551]: Librespot-go daemon starting...
Jul 18 21:42:14 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:14+01:00" level=info msg="generated new device id: 8ce9cbaad94f4b0bb5db660838a43aab3a8a6a81"
Jul 18 21:42:14 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:14+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:14 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:14+01:00" level=debug msg="obtained new client token: AAD6F6s/x5K8krhXenMKxlzjpcWttDWUVR8NQvA/7pIHNE+V+QvQvV4iPkxeHZcqMnyuo2FwGiRbUDiv/9pRKhs1CNY1ypQsoYkd8unn76Mdw05HVCX5sY79KTEZrWuxjWGi/vuGJk1ipX7naP4zjZjyzQbCGg/QmNWur30D6D5jV+WPqwTgwLaYXrfnG/Vjk27xQLDx9PmLxLTfCNX9xf0p/YhzYQIE2LbmdVmYvqDExex6G3rkz3rjkOzrNQ=="
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:14 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:14 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:14+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:15 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:15+01:00" level=debug msg="completed challenge"
Jul 18 21:42:15 richdacvolumio go-librespot[8551]: time="2025-07-18T21:42:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:42:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:16 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:18 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Jul 18 21:42:18 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:18 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:18 richdacvolumio go-librespot[8637]: Librespot-go daemon starting...
Jul 18 21:42:18 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:18+01:00" level=info msg="generated new device id: e20e45c87b5fa482ee7c72a79a742ae4c26ec91a"
Jul 18 21:42:18 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:18+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:18 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:18+01:00" level=debug msg="obtained new client token: AAC0Y/YPaR+YiXCE0JSibgmxeb5MG7K+Ze/i+WXSGovaOTzATZKQ6dsvtXweVbT0REJSZCCwPYNxd2l0jfAO2ITJ/IY2oPZfP+9QvJvqSxolTju4n5WYEnXv1tpPHsywPhZa+bN3pgoAS76BIzMcGgp+MMlLDs+QoZhvAtCYGS5/vImjYdAryHRV681x5dcRNHyKldAnVm0BLkzYb8MHaYOEIuhlxCdn9hxr93Assab3biGo4xpPUkYbrXqdMw=="
Jul 18 21:42:19 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:19 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:19+01:00" level=debug msg="new websocket client"
Jul 18 21:42:19 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket established
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:21+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:21 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42:21+01:00" level=debug msg="completed challenge"
Jul 18 21:42:21 richdacvolumio go-librespot[8637]: time="2025-07-18T21:42: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"
Jul 18 21:42:21 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:21 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:21 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket closed
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: Getting Spotify volume
Jul 18 21:42:22 richdacvolumio volumio[5899]: (node:5899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:22 richdacvolumio volumio[5899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 18 21:42:22 richdacvolumio volumio[5899]: (node:5899) 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: 7)
Jul 18 21:42:22 richdacvolumio volumio[5899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:22 richdacvolumio volumio[5899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:23 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:24 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:24 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35.
Jul 18 21:42:24 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:24 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:25 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:25 richdacvolumio go-librespot[8782]: Librespot-go daemon starting...
Jul 18 21:42:25 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42:25+01:00" level=info msg="generated new device id: f55d5ed5564365c16c1197ba530ca72918c9d76c"
Jul 18 21:42:25 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42:25+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:25 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42:25+01:00" level=debug msg="obtained new client token: AACkzjglL7GIHBpk7kWd7726feS4y2C4+gbDMRfV6+26KfvoYCk0o9WRyNALfax4YfmwZ4iyZ7vQ8uaEm908MMiXk0FxGzpx8nCYGC44fiYHjDM8TEkyRHq/7phUb3oQ85BB18hI49gEcSeC7Qy50khvADSzjrAYvk9No55lrWQJBVVKX3IP9UnXtho9awcKQ4FLhjrIwNN7H97QAbelxPbpXjOAUX+IwHffAe9OFCkwCTq83WKpx409J262Ng=="
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:25 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:26 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 18 21:42:26 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42:26+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:26 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42:26+01:00" level=debug msg="completed challenge"
Jul 18 21:42:26 richdacvolumio go-librespot[8782]: time="2025-07-18T21:42: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"
Jul 18 21:42:26 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:26 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:26 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:27 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:28 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:29 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:29 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36.
Jul 18 21:42:29 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:29 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:29 richdacvolumio go-librespot[8874]: Librespot-go daemon starting...
Jul 18 21:42:29 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42:29+01:00" level=info msg="generated new device id: ae263c1d8e65be6bacf0a44c1179efef5635fddb"
Jul 18 21:42:29 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42:29+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:29 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42:30+01:00" level=debug msg="obtained new client token: AAB0Oal2Z9/I2xxpEIbA/Unos+SI84BiYaIWeC0D06uoDTcFTH8ouIZ7EMJ5ilyfWhsVPwEtd5F/vUOFd4t3E2yu7uKT78tePnWBdEtUia7+E0UzfzTYGVuGee5w+NLe2zDK8yfVAwv/rgemH/G0MLMjEuhQJY5LUtSblQ6kCOE/zrYEho1aKwNQz/XpW7JQjEymTfnffvY2n3wMUJ84qvlf4L/7IDTN0HBVZ85MPvOxTB4cZ/RyIuwHEw4="
Jul 18 21:42:30 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42:30+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:30 richdacvolumio sudo[5973]: pam_unix(sudo:session): session closed for user root
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: Cannot mount NAS server at system boot, trial number 1 ,retrying in 5 seconds
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42:30+01:00" level=debug msg="completed challenge"
Jul 18 21:42:30 richdacvolumio go-librespot[8874]: time="2025-07-18T21:42: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"
Jul 18 21:42:30 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:30 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:30 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:31 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:32 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:33 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:34 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:34 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Jul 18 21:42:34 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:34 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:34 richdacvolumio go-librespot[8976]: Librespot-go daemon starting...
Jul 18 21:42:34 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42:34+01:00" level=info msg="generated new device id: e468da2cf2f673d4db018c4b9574023f819f71ea"
Jul 18 21:42:34 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42:34+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:34 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42:34+01:00" level=debug msg="obtained new client token: AACfuPuEQOkKQjv7telgbIHxi5Moma7TP6/AMMTwnjXAkNKikwFuB2aWM4Od2lZ5w7Q+qZg3OZiIjcVSBPCSeEre/DMvwMV1ZGBuFRz7tR1Z0jGX7NXMyiHhov/oUkO9uCHZbZLWrUnS1fuw8Iow2LlrPc8yrTr5mD3RrKnye8NSGyFDJnkCSeCIT8WyaHXhojOp8S9FfpJvJ7fVFm1NxmajRuC7sq8lQMJC4RqYCxtW/voEQKYraPPJ5wMzMg=="
Jul 18 21:42:34 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 18 21:42:34 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42:34+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:34 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:35 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42:35+01:00" level=debug msg="completed challenge"
Jul 18 21:42:35 richdacvolumio go-librespot[8976]: time="2025-07-18T21:42: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"
Jul 18 21:42:35 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:35 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:35 richdacvolumio sudo[9009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=2.1 192.168.0.89:d: /mnt/NAS/server
Jul 18 21:42:35 richdacvolumio sudo[9009]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:35 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:36 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:37 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:38 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Jul 18 21:42:38 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:38 richdacvolumio go-librespot[9060]: Librespot-go daemon starting...
Jul 18 21:42:38 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42:38+01:00" level=info msg="generated new device id: aa93707708d64e7accca0f69b0b73b7bae221eaf"
Jul 18 21:42:38 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42:38+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:38 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42:38+01:00" level=debug msg="obtained new client token: AAB8nbOT6OF4XCv8nJDuNsMBpMnPBC6+zAv7Gi0JbuapSbPPAQC7WKV9gCT1MsBJ9ihettUfvGnqECky207pNBLFJ5smjfMM8u9FyX/rDE4ZrtGqFPJSnAeY1eC97sepXG+2ZWI0NJaMftnGqQH6cp00TbYCL7hCys5J/37w9iw8jMxUqu8dqLN5GMHfiJs27XIUNLP20QZ1amGF1P3rcrSXCQzmPfW624J9qk6B2DMJu3dx5sBAi2ahLuD4ZA=="
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:38 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:38 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:38 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42:38+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:39 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42:39+01:00" level=debug msg="completed challenge"
Jul 18 21:42:39 richdacvolumio go-librespot[9060]: time="2025-07-18T21:42: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"
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:39 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:39 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:39 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:40 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:41 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:42 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Jul 18 21:42:42 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:42 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:42 richdacvolumio go-librespot[9161]: Librespot-go daemon starting...
Jul 18 21:42:42 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:42+01:00" level=info msg="generated new device id: 863d8ae12d5473a2778d12d2ba2c5ad979585532"
Jul 18 21:42:42 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:42+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:42 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:42+01:00" level=debug msg="new websocket client"
Jul 18 21:42:42 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket established
Jul 18 21:42:43 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:43+01:00" level=debug msg="obtained new client token: AAB8iAAF4hDO1P2nl6TR3NEVbjeVe8qtPLGnZjqlXuOqbpHQg1QwhqCnlyK3YlDcI+cStRwjgWYvBYm5XCUXXf7tojtyZwA7PWQYTDTGITobwXE/Zuk6UjXj3yD6BlHPTuvotZRPbLe2JWbNnyppiRWZT0jkbF2HzGtwliRftzk0/KFR190tcMiS982fY1jmriJ+vG4xW8ysnMaHtGIJiJqQJRezvFYIefZWdDwf+PcRvD+3slZiLeQjqkk="
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:43 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:44 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:44 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:44+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:44 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:45+01:00" level=debug msg="completed challenge"
Jul 18 21:42:45 richdacvolumio go-librespot[9161]: time="2025-07-18T21:42:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:42:45 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:45 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket closed
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: Getting Spotify volume
Jul 18 21:42:45 richdacvolumio volumio[5899]: (node:5899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:45 richdacvolumio volumio[5899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 18 21:42:45 richdacvolumio volumio[5899]: (node:5899) 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: 8)
Jul 18 21:42:45 richdacvolumio volumio[5899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:45 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:46 richdacvolumio volumio[5899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:46 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:47 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:48 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Jul 18 21:42:48 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:48 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:48 richdacvolumio go-librespot[9268]: Librespot-go daemon starting...
Jul 18 21:42:48 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:48+01:00" level=info msg="generated new device id: 5d6b6267577aae28239e7d034acd608b3c8abed6"
Jul 18 21:42:48 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:48+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:48 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:48 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:48+01:00" level=debug msg="obtained new client token: AAA8rlADdJfP2eolD7hO5MmeqlIZaqJA+41GZIbnFevf3Pom37GKCkUU7/9y/gf5JrA/uzkv4/vecUdmvEm0O/zwy3NoKjEo+fIYd2l/naJa9Tc4QoB4u5mZTVhZvh3JyYC+1NeUceQjrsPFsAryHjqMb2muhEN1CRtdfE2unHWm+ElD5aKSNSTrzCz4rS04XnAdNUDICG44LkSLS7u8ZhtC5bxQCXzAyINitT+6Xx113xWeWOY0hp/JA6v6Ww=="
Jul 18 21:42:49 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:49 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:49+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:49 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:49+01:00" level=debug msg="completed challenge"
Jul 18 21:42:49 richdacvolumio go-librespot[9268]: time="2025-07-18T21:42:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:42:49 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:49 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:49 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:50 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:51 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Jul 18 21:42:52 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:52 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:52 richdacvolumio go-librespot[9375]: Librespot-go daemon starting...
Jul 18 21:42:52 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:52+01:00" level=info msg="generated new device id: f9c1ff25b847f9975a83ab31391569230b893e3e"
Jul 18 21:42:52 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:52+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:52 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:53 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:53+01:00" level=debug msg="obtained new client token: AADq/J+aJyKgY99hdYnq/7zJpFJvNhi53Lxkm/zRsjd0kDshcILpKIOiK9BwV9P8BDMlsylKCZdGLEL6PUTwYZVXlw3z1xTQgwxPFUw7V2OLfazFUmDc10AkywXGYtqpBmCDxz2tsPsDB3L8IT8CWvn2kruyjHP5zy+Qo/+A3mN9qgBUeqI9WB1XobTTShC6NHtGYjTr+nxjgCv/bppplrUOgwO9U+fyI75xKNMgIxLgpN7BomNER9AzMrE="
Jul 18 21:42:53 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:53 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:53+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:53 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:53+01:00" level=debug msg="completed challenge"
Jul 18 21:42:53 richdacvolumio go-librespot[9375]: time="2025-07-18T21:42:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:42:53 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:53 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:53 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:54 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:55 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:56 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:42:57 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:42:57 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42.
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:42:57 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:42:57 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:42:57 richdacvolumio go-librespot[9461]: Librespot-go daemon starting...
Jul 18 21:42:57 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:57+01:00" level=info msg="generated new device id: 9ca0f258cf3e5cafaeea28a52874e2d63d4664ea"
Jul 18 21:42:57 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:57+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:57 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:57+01:00" level=debug msg="obtained new client token: AAD0fugarCAXUL7sZqXkr28CmGiF4f29gYWIVDtAYOgpn861Xkho97j9mpAufdglCtIUerc1qv91EaNKfSRbRWZx8/o22std4k2nu/r5XxIyzjdHUmlBWVUqZO4p1l7Uw66SzQKx5iETNLnGQUVjFXkpUptI4kHSXvYhVmIy+YZL1uoxfnZpB4uCKjrkr0YCsD0F42pNcyu7lFl9+GBR05PHDUURaPqjMnSxzLisw04gnzC13qsXw+cykUS3dA=="
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:57 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:57 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:42:57 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:57+01:00" level=debug msg="completed keyexchange"
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:58 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:58+01:00" level=debug msg="completed challenge"
Jul 18 21:42:58 richdacvolumio go-librespot[9461]: time="2025-07-18T21:42:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:42:58 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:42:58 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:58 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:42:59 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:00 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:43:01 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43.
Jul 18 21:43:01 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:43:01 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:43:01 richdacvolumio go-librespot[9602]: Librespot-go daemon starting...
Jul 18 21:43:01 richdacvolumio go-librespot[9602]: time="2025-07-18T21:43:01+01:00" level=info msg="generated new device id: 8587a9e51f1ce15dacd6810d89f848393ab9bc4b"
Jul 18 21:43:01 richdacvolumio go-librespot[9602]: time="2025-07-18T21:43:01+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:01 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio go-librespot[9602]: time="2025-07-18T21:43:02+01:00" level=debug msg="obtained new client token: AAB8uVzbwYDFHb3NKOTcbeJyn+kC9jE5BtLggszZjvwjKegBUka5ehX1ZPVlfJTh64/byymnz8oLG+/CdOmP0R09Aek9uaFEtRU4WRAOxHrpITLFbEC/YHek5spK58aZElET92VrAomXfUlnNE6KGHyt8P3gGJhU9tJWL3ab3QuEDTgd77NIfa91HcaEeyVfUoE7rqmMhWN653Pv/6vUgMK2f5hdf83laU65P20n2UpRkEqf8F/E/8ijG8E="
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio go-librespot[9602]: time="2025-07-18T21:43:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:02 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:02 richdacvolumio go-librespot[9602]: time="2025-07-18T21:43:02+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"
Jul 18 21:43:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:43:02 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:03 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:04 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:05 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:43:05 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Jul 18 21:43:05 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:43:05 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:43:05 richdacvolumio go-librespot[9691]: Librespot-go daemon starting...
Jul 18 21:43:05 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:05+01:00" level=info msg="generated new device id: 8597c6da8213136ab925ca8aabadc5a2ee4665b9"
Jul 18 21:43:05 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:05+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:43:06 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:06+01:00" level=debug msg="obtained new client token: AAAn8aZjErQqL2ID5cMngZAgq7TOnDgFHq5cdO6qIhX++U7p3+4sjTlSTB71WR1wkK9NnnsRsyI7mgTOkiZzbbFVr/rq4lCEWg7q2Sfqt25gE/EVZFWYZGszncnY9nJjeKEkzC6Jy6cho7qmPy/HFJ/32w+NBV1V+OGA/oI4u4As+AgAhiMRIFMnbarGM0jnXxdJ+GyIJWGuQvDahZY3dsEb36/nTkpKaumniAdce4gINt3Vt8hq9Fg10yo="
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:06 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:06+01:00" level=debug msg="new websocket client"
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket established
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:06 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:43:06 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:06+01:00" level=debug msg="completed keyexchange"
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:06 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:07 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:07+01:00" level=debug msg="completed challenge"
Jul 18 21:43:07 richdacvolumio go-librespot[9691]: time="2025-07-18T21:43:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:43:07 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:43:07 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket closed
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:07 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:08 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: Getting Spotify volume
Jul 18 21:43:09 richdacvolumio volumio[5899]: (node:5899) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:43:09 richdacvolumio volumio[5899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 18 21:43:09 richdacvolumio volumio[5899]: (node:5899) 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: 9)
Jul 18 21:43:09 richdacvolumio volumio[5899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:09 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:43:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:43:10 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Jul 18 21:43:10 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:43:10 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:43:10 richdacvolumio go-librespot[9777]: Librespot-go daemon starting...
Jul 18 21:43:10 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:10+01:00" level=info msg="generated new device id: 92325f03b5c472066761b176b24835243c793121"
Jul 18 21:43:10 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:10+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:10+01:00" level=debug msg="obtained new client token: AACGJEr+gEgzfkDoowqeeSzA7/1dXKSa8MfFzoly0eYEzw/T18SkUx/XlqOcWcuVi05uzjge9lLWd3noMsjUeCWOZ0yKcDW/J7v7BzOzMHLE88w2Qg1+kCsGiJ0TgBSm4MqKNDi8irhFqattznGRav6VVYFGBHedsXRkYCOrba4bh6v8E9N5ExYuXRKUoygS6j5TRJslvc14RL6RN6O6O2S39uim5OQsDu0wHLSH+g42XGsFWQvKdNxgyM2i6A=="
Jul 18 21:43:10 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:10 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:10 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:10+01:00" level=debug msg="completed keyexchange"
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:11 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:11+01:00" level=debug msg="completed challenge"
Jul 18 21:43:11 richdacvolumio go-librespot[9777]: time="2025-07-18T21:43:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:43:11 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:43:11 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:11 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:12 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:13 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:43:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Jul 18 21:43:14 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:43:14 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:43:14 richdacvolumio go-librespot[9878]: Librespot-go daemon starting...
Jul 18 21:43:14 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:14+01:00" level=info msg="generated new device id: 59d337b9c5ee61d144e9249bad5e4f2cf6cc3520"
Jul 18 21:43:14 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:14+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:14 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:15+01:00" level=debug msg="obtained new client token: AACz8K8TtHZ9F3OBPAWEE4Fj9T6CL7LmTuUhoXntEc9LRl6ZJitraH0h6uOvMipVRADyzZrYMfYMS/mxwISrgG5/kJAoE3qMuIZvwcGTcxL9mzxZxA24tkciuarMMEObJmoTAg83jU3VCR9SS7MN64w26y8Ul1fTBaistnvwpUL3qaGDvy0qFS0MbNLZXOrOt8Xurz+AyeEDQzOoOLzHkeevx4pbYJnIOdH0kIWoa9yDdmJucqfPenAdJ1w="
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 18 21:43:15 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:15+01:00" level=debug msg="completed keyexchange"
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:15 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:15 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:15+01:00" level=debug msg="completed challenge"
Jul 18 21:43:15 richdacvolumio go-librespot[9878]: time="2025-07-18T21:43:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Jul 18 21:43:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:43:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:16 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:17 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:18 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 18 21:43:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Jul 18 21:43:19 richdacvolumio systemd[1]: Stopped go-librespot Daemon.
Jul 18 21:43:19 richdacvolumio systemd[1]: Started go-librespot Daemon.
Jul 18 21:43:19 richdacvolumio go-librespot[9965]: Librespot-go daemon starting...
Jul 18 21:43:19 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:19+01:00" level=info msg="generated new device id: e022875f912ae8837d71e69a62f7235887e02121"
Jul 18 21:43:19 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:19+01:00" level=debug msg="stored credentials found for eviesdaddythemainman"
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: Initializing connection to go-librespot Websocket
Jul 18 21:43:19 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:19+01:00" level=debug msg="new websocket client"
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket established
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:19 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:19 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:19+01:00" level=debug msg="obtained new client token: AACKF8Y9NODjVKv0DC+YKKtDaKV2AOUbfZQQE0KlPoF4jW1nsQjTQytppoJHVi9U6vm2pJIQzmMuxDRg5srL597ohey0nncGPMCGeM3LWL6kCMvUI32frKpV2gclPsS/VX7o7PGfWheKg8JJTw11oR11y9WsCVqLbwFoUgLRAuLSR03YXeUtKKkcwnRjAeSm6+GmbiHdRd2hvDwAT8AKyS11+g7JMbN21j2MXeJN0DgWIFMQg98Y08zu6TQxnQ=="
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:20 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:20 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:21 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: Getting Spotify volume
Jul 18 21:43:22 richdacvolumio volumio[5899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Jul 18 21:43:22 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:22+01:00" level=debug msg="completed keyexchange"
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 21:43:22 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43:22+01:00" level=debug msg="completed challenge"
Jul 18 21:43:22 richdacvolumio go-librespot[9965]: time="2025-07-18T21:43: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"
Jul 18 21:43:22 richdacvolumio volumio[5899]: (node:5899) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 18 21:43:22 richdacvolumio volumio[5899]: at connResetException (internal/errors.js:607:14)
Jul 18 21:43:22 richdacvolumio volumio[5899]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 18 21:43:22 richdacvolumio volumio[5899]: at Socket.emit (events.js:327:22)
Jul 18 21:43:22 richdacvolumio volumio[5899]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 18 21:43:22 richdacvolumio volumio[5899]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 18 21:43:22 richdacvolumio volumio[5899]: (node:5899) 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: 10)
Jul 18 21:43:22 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 18 21:43:22 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: Connection to go-librespot Websocket closed
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CoreCommandRouter::volumioGetState
Jul 18 21:43:22 richdacvolumio volumio[5899]: info: CorePlayQueue::getTrack 0
Jul 18 21:43:23 richdacvolumio volumio[5899]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 18 21:43:23 richdacvolumio volumio[5899]: TypeError: Cannot read property 'length' of undefined
Jul 18 21:43:23 richdacvolumio volumio[5899]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25
Jul 18 21:43:23 richdacvolumio volumio[5899]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13
Jul 18 21:43:23 richdacvolumio volumio[5899]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at Parser.emit (events.js:315:20)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at IncomingMessage.emit (events.js:327:22)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 18 21:43:23 richdacvolumio volumio[5899]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 18 21:43:23 richdacvolumio volumio[5899]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 18 21:43:23 richdacvolumio sudo[10070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 21:42
Jul 18 21:43:23 richdacvolumio sudo[10070]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST"
VOLUMIO_VERSION="3.816"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"