-- Logs begin at Thu 2025-10-23 17:58:17 CEST, end at Thu 2025-10-23 18:41:48 CEST. -- Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo go-librespot[19817]: time="2025-10-23T18:40:00+02:00" level=debug msg="completed challenge" Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:00 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:00 rivo go-librespot[19817]: time="2025-10-23T18:40:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:00 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:00 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:00 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:00 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:01 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:01 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:01 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:01 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:01 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:02 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:03 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:03 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 418. Oct 23 18:40:03 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:03 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:03 rivo go-librespot[19833]: Librespot-go daemon starting... Oct 23 18:40:03 rivo go-librespot[19833]: time="2025-10-23T18:40:03+02:00" level=info msg="generated new device id: 2e8c03121ac075ae65975655651109b479918281" Oct 23 18:40:03 rivo go-librespot[19833]: time="2025-10-23T18:40:03+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:03 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:03 rivo go-librespot[19833]: time="2025-10-23T18:40:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:03 rivo go-librespot[19833]: time="2025-10-23T18:40:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:03 rivo go-librespot[19833]: time="2025-10-23T18:40:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:04 rivo go-librespot[19833]: time="2025-10-23T18:40:04+02:00" level=debug msg="zeroconf server listening on port 44577" Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:04 rivo go-librespot[19833]: time="2025-10-23T18:40:04+02:00" level=debug msg="obtained new client token: AACUci0p6CN2jIdTs3/drG1ftiH2pH8NdKVFweeN4dgbB5zhWgeAKoAmoVU5gk7cjxBhERgw95gFRwdJJ7MrOW5mbG5a7j/IlLh0c3y2YwoLtNFNm28nnddt/86eNF5BKfZ5wvaHwtLslW4UgE6mYajEu+LlCY4sGfVWU33uWKloulFlK7f7m5B/JDg5qO4GMYjYu2BVNJY7S/CPYHiC4Rqc+LeY9yufVQPl2exsU9NZzPvuRVZ0/0UKCiA=" Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:04 rivo go-librespot[19833]: time="2025-10-23T18:40:04+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:04 rivo go-librespot[19833]: time="2025-10-23T18:40:04+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:04 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:04 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:05 rivo volumio[3306]: Upnp client error: Error: This socket has been ended by the other party Oct 23 18:40:05 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:40:05 rivo volumio[3306]: Upnp client error: Error: This socket has been ended by the other party Oct 23 18:40:05 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:40:05 rivo go-librespot[19833]: time="2025-10-23T18:40:05+02:00" level=debug msg="completed challenge" Oct 23 18:40:05 rivo go-librespot[19833]: time="2025-10-23T18:40:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:05 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:05 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:05 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 23 18:40:05 rivo volumio[3306]: at connResetException (internal/errors.js:639:14) Oct 23 18:40:05 rivo volumio[3306]: at Socket.socketOnEnd (_http_client.js:499:23) Oct 23 18:40:05 rivo volumio[3306]: at Socket.emit (events.js:412:35) Oct 23 18:40:05 rivo volumio[3306]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 23 18:40:05 rivo volumio[3306]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 23 18:40:05 rivo volumio[3306]: (node:3306) 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: 205) Oct 23 18:40:05 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:05 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:05 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:40:06 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Oct 23 18:40:08 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:08 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:08 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:08 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 419. Oct 23 18:40:08 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:08 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:08 rivo go-librespot[19864]: Librespot-go daemon starting... Oct 23 18:40:08 rivo go-librespot[19864]: time="2025-10-23T18:40:08+02:00" level=info msg="generated new device id: bcd38dd74a846c1f40c0ad95ee7bb99419c7d192" Oct 23 18:40:08 rivo go-librespot[19864]: time="2025-10-23T18:40:08+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:08 rivo go-librespot[19864]: time="2025-10-23T18:40:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:08 rivo go-librespot[19864]: time="2025-10-23T18:40:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:08 rivo go-librespot[19864]: time="2025-10-23T18:40:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:08 rivo go-librespot[19864]: time="2025-10-23T18:40:08+02:00" level=debug msg="zeroconf server listening on port 36969" Oct 23 18:40:09 rivo go-librespot[19864]: time="2025-10-23T18:40:09+02:00" level=debug msg="obtained new client token: AAC/fCqRdN/oMSoZQgeki/dlnIJkL8BCkoTX2NOPvMQpy83c0TnAXDrv/2JgqPeN0RAJiA5Q5TVp5+vo8pAEGaxFLzYKO+BKuMx4BW1iF41ZZW7tC0TfU/01mL7xeCdVpJnHyudABMH1oJrMKFuhwC5QYRgpS6kuUXjlkJfg/oNzUz6z9xCL+pj4aPFsMdtnEEJgYgWiZ2WDUXeU9qWXE/V8NEZ+pBD7uNa0Gk2rtmpihgAW+hPOKoNE" Oct 23 18:40:09 rivo go-librespot[19864]: time="2025-10-23T18:40:09+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:09 rivo go-librespot[19864]: time="2025-10-23T18:40:09+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:10 rivo go-librespot[19864]: time="2025-10-23T18:40:10+02:00" level=debug msg="completed challenge" Oct 23 18:40:10 rivo go-librespot[19864]: time="2025-10-23T18:40:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:10 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:10 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:11 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:11 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:13 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:13 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 420. Oct 23 18:40:13 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:13 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:13 rivo go-librespot[19895]: Librespot-go daemon starting... Oct 23 18:40:13 rivo go-librespot[19895]: time="2025-10-23T18:40:13+02:00" level=info msg="generated new device id: 91235411a089321d1c75b007fb1cc8946232e361" Oct 23 18:40:13 rivo go-librespot[19895]: time="2025-10-23T18:40:13+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:13 rivo go-librespot[19895]: time="2025-10-23T18:40:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:13 rivo go-librespot[19895]: time="2025-10-23T18:40:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:13 rivo go-librespot[19895]: time="2025-10-23T18:40:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:13 rivo go-librespot[19895]: time="2025-10-23T18:40:13+02:00" level=debug msg="zeroconf server listening on port 43427" Oct 23 18:40:14 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:14 rivo go-librespot[19895]: time="2025-10-23T18:40:14+02:00" level=debug msg="new websocket client" Oct 23 18:40:14 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:40:14 rivo go-librespot[19895]: time="2025-10-23T18:40:14+02:00" level=debug msg="obtained new client token: AAAQJX+ioaveTw6S8DJwkCGgdHIBGFhqUqb2uFECrGBp7ute5GsSYBRqgdh463g46EKWQSvtX8bfyKZ4WAgg1TURnFxtVlpmOR3opk7bN3t8owNmp4THfiJiF9l8onOXcDMsV/dgwUKzqgBB7SPYIxOeVfEHNl1Idv5TgJMOeTS9ZvOL//YRbQTGa+7DdbMcqd2to2H4zW0KDeUdBpVeLn5Kg7o4swEvkqmGXQ/ZFnWy0/HxnECcWPd7oQQ=" Oct 23 18:40:14 rivo go-librespot[19895]: time="2025-10-23T18:40:14+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:14 rivo go-librespot[19895]: time="2025-10-23T18:40:14+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:15 rivo go-librespot[19895]: time="2025-10-23T18:40:15+02:00" level=debug msg="completed challenge" Oct 23 18:40:15 rivo go-librespot[19895]: time="2025-10-23T18:40:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:15 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:40:15 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:15 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:17 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:40:17 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:17 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:40:17 rivo volumio[3306]: (node:3306) 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: 206) Oct 23 18:40:17 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 23 18:40:17 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:17 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:17 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:40:18 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:18 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:18 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:18 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 421. Oct 23 18:40:18 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:18 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:18 rivo go-librespot[19931]: Librespot-go daemon starting... Oct 23 18:40:18 rivo go-librespot[19931]: time="2025-10-23T18:40:18+02:00" level=info msg="generated new device id: 3d11e6c6f21c4b85324ac0667ee4680df99d44a5" Oct 23 18:40:18 rivo go-librespot[19931]: time="2025-10-23T18:40:18+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:19 rivo go-librespot[19931]: time="2025-10-23T18:40:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:19 rivo go-librespot[19931]: time="2025-10-23T18:40:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:19 rivo go-librespot[19931]: time="2025-10-23T18:40:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:19 rivo go-librespot[19931]: time="2025-10-23T18:40:19+02:00" level=debug msg="zeroconf server listening on port 33979" Oct 23 18:40:19 rivo go-librespot[19931]: time="2025-10-23T18:40:19+02:00" level=debug msg="obtained new client token: AADuF+oK+GGKrIxBgpvalLbGuU9mbRAzTSHc86yRis1RWYiGf19lQnC1lnP5wy+nLMwukU1C0Wd7GLmBcvzqY6Wi5PhnECMbNoayT3pEzFC1hR/dItZuTZLKnFBwyZFgga/+XR8xokdK80ERK7ZwphHVqC55CQDTeOJOAVYpdfJ4BqnpUA4FsGuEYnt6N6jf5EB5+AAz0kD+h7yCD3dUN0vpxjAD8FI6XMlXJU8J3gHBLCvDgfXHehf4eTg=" Oct 23 18:40:19 rivo go-librespot[19931]: time="2025-10-23T18:40:19+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:20 rivo go-librespot[19931]: time="2025-10-23T18:40:20+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:20 rivo go-librespot[19931]: time="2025-10-23T18:40:20+02:00" level=debug msg="completed challenge" Oct 23 18:40:20 rivo go-librespot[19931]: time="2025-10-23T18:40:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:20 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:20 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:21 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:21 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:23 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:23 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 422. Oct 23 18:40:23 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:23 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:23 rivo go-librespot[19953]: Librespot-go daemon starting... Oct 23 18:40:23 rivo go-librespot[19953]: time="2025-10-23T18:40:23+02:00" level=info msg="generated new device id: bc299be364f2bd5b413142601a3a081aef849203" Oct 23 18:40:23 rivo go-librespot[19953]: time="2025-10-23T18:40:23+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=debug msg="zeroconf server listening on port 37705" Oct 23 18:40:24 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=debug msg="new websocket client" Oct 23 18:40:24 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=debug msg="obtained new client token: AACt8VD93FgQvrqIFmRK9tHaJxCZlOPWmzudECgj73jS6d3g1UJDH6zCkeWinom6kn7xSh3m/LYx0kIdOXGztighlhaJqfw+/a4t+3N53Ygiq2lpNVjS3VyaeeGKPoeYwnO3/JPSkqDhY3WbFeOabSmOPioc/EUoL4NRLRCKxXBVsgQjF2CACBTJgQw8lmvlmRsc5E/Flg/sbgcXF8I/jNFeFjFFN+MA7o+c6+W0dhmDKSbfe4H4DPhf4aY=" Oct 23 18:40:24 rivo go-librespot[19953]: time="2025-10-23T18:40:24+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:25 rivo go-librespot[19953]: time="2025-10-23T18:40:25+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:25 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 23 18:40:25 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 23 18:40:25 rivo volumio[3306]: info: Discovery: Getting this device information Oct 23 18:40:25 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:25 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:25 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 23 18:40:25 rivo go-librespot[19953]: time="2025-10-23T18:40:25+02:00" level=debug msg="completed challenge" Oct 23 18:40:25 rivo go-librespot[19953]: time="2025-10-23T18:40:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:25 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:25 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:40:25 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:27 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:40:27 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:27 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:40:27 rivo volumio[3306]: (node:3306) 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: 207) Oct 23 18:40:27 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:40:27 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:27 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:27 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:40:28 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:28 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:28 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:28 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 423. Oct 23 18:40:28 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:28 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:28 rivo go-librespot[19988]: Librespot-go daemon starting... Oct 23 18:40:28 rivo go-librespot[19988]: time="2025-10-23T18:40:28+02:00" level=info msg="generated new device id: 84affee88ad3dc91588f66186b8e2bfab768a6c4" Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=debug msg="zeroconf server listening on port 40917" Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=debug msg="obtained new client token: AAC7mdTXULranv0vIMw5f7ap7PGGeo++U8EnYDls3RgaIPuqUttlsxaMGKgiA8TNO8m6Ix3IM0oXJPNIQEo8fO/pLIWbAIfZJ96I6RxcUS0wScr7Y0K5xQyA4Y/2Y+JrDsFO2ruIenpnZsNrA6//4czDeuDXIr9tyCAI55jDAORfhNO+k3oMVCmF/Hrouoqhy2CJoYhWM6zoUsH3fwiGk0klp8/cVIP/ZCA8WsO3VspdVS0DHj6HORgHik4=" Oct 23 18:40:29 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Oct 23 18:40:29 rivo go-librespot[19988]: time="2025-10-23T18:40:29+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:30 rivo go-librespot[19988]: time="2025-10-23T18:40:30+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:30 rivo go-librespot[19988]: time="2025-10-23T18:40:30+02:00" level=debug msg="completed challenge" Oct 23 18:40:30 rivo go-librespot[19988]: time="2025-10-23T18:40:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:30 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:30 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:31 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:31 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:33 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:33 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 424. Oct 23 18:40:33 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:33 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:33 rivo go-librespot[20051]: Librespot-go daemon starting... Oct 23 18:40:33 rivo go-librespot[20051]: time="2025-10-23T18:40:33+02:00" level=info msg="generated new device id: d9f4f6467eae5e12d51ca927d6c9ed6bbf2debfb" Oct 23 18:40:33 rivo go-librespot[20051]: time="2025-10-23T18:40:33+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:34 rivo go-librespot[20051]: time="2025-10-23T18:40:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 23 18:40:34 rivo go-librespot[20051]: time="2025-10-23T18:40:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 23 18:40:34 rivo go-librespot[20051]: time="2025-10-23T18:40:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 23 18:40:34 rivo go-librespot[20051]: time="2025-10-23T18:40:34+02:00" level=debug msg="zeroconf server listening on port 44681" Oct 23 18:40:34 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:34 rivo go-librespot[20051]: time="2025-10-23T18:40:34+02:00" level=debug msg="new websocket client" Oct 23 18:40:34 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:40:34 rivo go-librespot[20051]: time="2025-10-23T18:40:34+02:00" level=debug msg="obtained new client token: AAD3JjB1wKypBnf271D7hCPAN/N9EGviw5iXqfVk6y2Jzc43G5+VoxzX2IMi1Ntb34oO4tQUPbBYWByy9jCwQuymVrLw7kaZiq55ms20E1ZBfUhjGkTfeCmqZA+zqzqnWw8WdEx9YP8vyGsribrwFQQPYK3Xz3H2ko6Y3XnhFOxgbpaLB8ixhNkEfU+oqxT2VSX7II6xlOPUFXVtR7xl6R4/VKmNRrQZvluvWUzaXItjXUNZS+f9d142vrE=" Oct 23 18:40:35 rivo go-librespot[20051]: time="2025-10-23T18:40:35+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:35 rivo go-librespot[20051]: time="2025-10-23T18:40:35+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:35 rivo go-librespot[20051]: time="2025-10-23T18:40:35+02:00" level=debug msg="completed challenge" Oct 23 18:40:35 rivo go-librespot[20051]: time="2025-10-23T18:40:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:35 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:35 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:40:35 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:37 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:40:37 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:37 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:40:37 rivo volumio[3306]: (node:3306) 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: 208) Oct 23 18:40:37 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Oct 23 18:40:37 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:37 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:37 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:40:38 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:38 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:39 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:39 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 425. Oct 23 18:40:39 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:39 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:39 rivo go-librespot[20087]: Librespot-go daemon starting... Oct 23 18:40:39 rivo go-librespot[20087]: time="2025-10-23T18:40:39+02:00" level=info msg="generated new device id: 10ee216a3e7eda882e012c97f8c70471f2394781" Oct 23 18:40:39 rivo go-librespot[20087]: time="2025-10-23T18:40:39+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:39 rivo go-librespot[20087]: time="2025-10-23T18:40:39+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:39 rivo go-librespot[20087]: time="2025-10-23T18:40:39+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:39 rivo go-librespot[20087]: time="2025-10-23T18:40:39+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:39 rivo go-librespot[20087]: time="2025-10-23T18:40:39+02:00" level=debug msg="zeroconf server listening on port 46357" Oct 23 18:40:40 rivo go-librespot[20087]: time="2025-10-23T18:40:40+02:00" level=debug msg="obtained new client token: AACPXd95NpPrcFHPiGAQq0YKNSGCNqgT32mp78Hk1E8luy3Xe86xxKHrsmu7K7SnsnsSQGleWcrJRTvdly7Q+B/27B51/tizTnbzTkOMwsl78jOR3oSfeurm43N1pWaK95p/DuH6b7n0HmfNa7IgTKU/CdLOSqfOXWfR5PAkyC4Gh3JYfs679UVwzjUkRS/42QUdby8kxck6fQgnqXS6glw60KmboVxtN91X3YFhzkIc7/oaXrF+hgIz" Oct 23 18:40:40 rivo go-librespot[20087]: time="2025-10-23T18:40:40+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:40 rivo go-librespot[20087]: time="2025-10-23T18:40:40+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:41 rivo go-librespot[20087]: time="2025-10-23T18:40:41+02:00" level=debug msg="completed challenge" Oct 23 18:40:41 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Oct 23 18:40:41 rivo go-librespot[20087]: time="2025-10-23T18:40:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:41 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:41 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:41 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:41 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:44 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:44 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 426. Oct 23 18:40:44 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:44 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:44 rivo go-librespot[20106]: Librespot-go daemon starting... Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=info msg="generated new device id: 5d6cf03aab05844e27856d1d82c4c8b8ebdfdca4" Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=debug msg="zeroconf server listening on port 34899" Oct 23 18:40:44 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100 from 192.168.1.102 UA: Mozilla/5.0 (Linux; Android 11; moto g 5G Build/RZKS31.Q3-25-15-11; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.207 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 23 18:40:44 rivo go-librespot[20106]: time="2025-10-23T18:40:44+02:00" level=debug msg="obtained new client token: AABKNCMpxPdUsBcNv9giGbz2e4L1wFeH/eTpd3AnrlrhwikxiEtHiHzv7GSlYpNo9fJPyqsweAbYGpIR9UrKtfAH9KlByQXB5A6XI0Qte9UJk2Lqq7aTUOjioHtywijOnIfV4awKQxvqd6qlKpeoVsRZBnTPC4ptSyjCzivcLoCaZy+rLOejpWJFgTQr50S0xyIYBxD8OpYKfGHFXISCTxEiw/pMsNPmU+UDAkWb7twengGzZgDxgPOJvXM=" Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::volumioGetVisibleSources Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:44 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 23 18:40:44 rivo volumio[3306]: info: Received Get System Info Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 23 18:40:44 rivo volumio[3306]: info: Discovery: Getting this device information Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:44 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 23 18:40:44 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:44 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:45 rivo volumio[3306]: info: Listing playlists Oct 23 18:40:45 rivo volumio[3306]: info: CoreCommandRouter::volumioGetQueue Oct 23 18:40:45 rivo volumio[3306]: info: CoreStateMachine::getQueue Oct 23 18:40:45 rivo volumio[3306]: info: CorePlayQueue::getQueue Oct 23 18:40:45 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:45 rivo go-librespot[20106]: time="2025-10-23T18:40:45+02:00" level=debug msg="new websocket client" Oct 23 18:40:45 rivo go-librespot[20106]: time="2025-10-23T18:40:45+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:45 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:40:45 rivo go-librespot[20106]: time="2025-10-23T18:40:45+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:45 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 23 18:40:45 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:45 rivo go-librespot[20106]: time="2025-10-23T18:40:45+02:00" level=debug msg="completed challenge" Oct 23 18:40:45 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:45 rivo go-librespot[20106]: time="2025-10-23T18:40:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:45 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:45 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:45 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:45 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:40:46 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:46 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:46 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:46 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:47 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:47 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:47 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:47 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:47 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:48 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 427. Oct 23 18:40:48 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:48 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:48 rivo go-librespot[20136]: Librespot-go daemon starting... Oct 23 18:40:48 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:48 rivo go-librespot[20136]: time="2025-10-23T18:40:48+02:00" level=info msg="generated new device id: 3c2268752a1ed6b30a1c9dd6b9615f799b08f582" Oct 23 18:40:48 rivo go-librespot[20136]: time="2025-10-23T18:40:48+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:49 rivo go-librespot[20136]: time="2025-10-23T18:40:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 23 18:40:49 rivo go-librespot[20136]: time="2025-10-23T18:40:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 23 18:40:49 rivo go-librespot[20136]: time="2025-10-23T18:40:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 23 18:40:49 rivo go-librespot[20136]: time="2025-10-23T18:40:49+02:00" level=debug msg="zeroconf server listening on port 39655" Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - Oct 23 18:40:49 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:40:49 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:49 rivo go-librespot[20136]: time="2025-10-23T18:40:49+02:00" level=debug msg="obtained new client token: AAC97+US04q07OGQmaagXsRSxM72rTW7suiefdPn+1goaqEEpkl2v1vp4qGS/a5zLrBzyZfP0k9qpZCFvA3UvUT+Ip1eox64hB8HABeIhltn1EYDz4aruqRCyyxaGEJ9v36ma4aFMyRKOwJgoWA2X+go5vyzgzjwvvrWfgs6/JulqmXO8lDUkErVmpV1BfkklQjxsTitZh49NFalNmNLiEv983vawj5IzM7F1HvGtv1eSSuz0xFWkl8Vf2Y=" Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:49 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo go-librespot[20136]: time="2025-10-23T18:40:50+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo go-librespot[20136]: time="2025-10-23T18:40:50+02:00" level=info msg="connected to ap-gew4.spotify.com:443" Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo go-librespot[20136]: time="2025-10-23T18:40:50+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:40:50 rivo go-librespot[20136]: time="2025-10-23T18:40:50+02:00" level=debug msg="completed challenge" Oct 23 18:40:50 rivo volumio[3306]: Upnp client error: Error: This socket has been ended by the other party Oct 23 18:40:50 rivo go-librespot[20136]: time="2025-10-23T18:40:50+02:00" level=debug msg="new websocket client" Oct 23 18:40:50 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:40:50 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 23 18:40:50 rivo go-librespot[20136]: time="2025-10-23T18:40:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:51 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:51 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:51 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 23 18:40:51 rivo volumio[3306]: at connResetException (internal/errors.js:639:14) Oct 23 18:40:51 rivo volumio[3306]: at Socket.socketOnEnd (_http_client.js:499:23) Oct 23 18:40:51 rivo volumio[3306]: at Socket.emit (events.js:412:35) Oct 23 18:40:51 rivo volumio[3306]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 23 18:40:51 rivo volumio[3306]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 23 18:40:51 rivo volumio[3306]: (node:3306) 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: 209) Oct 23 18:40:51 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:51 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:51 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:40:51 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:40:53 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:40:53 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:53 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:40:53 rivo volumio[3306]: (node:3306) 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: 210) Oct 23 18:40:53 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 23 18:40:54 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:40:54 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:40:54 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:40:54 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:54 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:54 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:54 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 428. Oct 23 18:40:54 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:54 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:54 rivo go-librespot[20157]: Librespot-go daemon starting... Oct 23 18:40:54 rivo go-librespot[20157]: time="2025-10-23T18:40:54+02:00" level=info msg="generated new device id: b2df1fc8a9fe1d0c5c1adf95af2b19c2a1f96b77" Oct 23 18:40:54 rivo go-librespot[20157]: time="2025-10-23T18:40:54+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:54 rivo go-librespot[20157]: time="2025-10-23T18:40:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:54 rivo go-librespot[20157]: time="2025-10-23T18:40:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:54 rivo go-librespot[20157]: time="2025-10-23T18:40:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:54 rivo go-librespot[20157]: time="2025-10-23T18:40:54+02:00" level=debug msg="zeroconf server listening on port 37567" Oct 23 18:40:55 rivo go-librespot[20157]: time="2025-10-23T18:40:55+02:00" level=debug msg="obtained new client token: AABdTm9l9hS0pJNiAKZKlKq/rAl3rQ4KNXwU/Pm+4fdlL9h4TdAvTxq7uv8VhEj/ZChojFjiWSysJQPfXvD7Ut/O+syiaB+CGUP1GCW6LUS/wbumrd4H58d5iPX+f9qKHKsO/MTV7NrhZI3iKREUjdwY1SwxcLNv8OM6ln19zkAYGX04i8OO7RKMErZr4RmDlvBQ+skfyoNrEeMgalGbBTBOhmruQ/QgDYoi92g/AMO5vMHghr/sbKAp/cI=" Oct 23 18:40:55 rivo go-librespot[20157]: time="2025-10-23T18:40:55+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:40:55 rivo go-librespot[20157]: time="2025-10-23T18:40:55+02:00" level=debug msg="completed keyexchange" Oct 23 18:40:55 rivo go-librespot[20157]: time="2025-10-23T18:40:55+02:00" level=debug msg="completed challenge" Oct 23 18:40:55 rivo go-librespot[20157]: time="2025-10-23T18:40:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:40:55 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:40:55 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:40:57 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:40:57 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:40:59 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:40:59 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 429. Oct 23 18:40:59 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:40:59 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:40:59 rivo go-librespot[20191]: Librespot-go daemon starting... Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=info msg="generated new device id: c208f27da18c2811c334f9f02abcc3504cb99317" Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=debug msg="zeroconf server listening on port 37539" Oct 23 18:40:59 rivo go-librespot[20191]: time="2025-10-23T18:40:59+02:00" level=debug msg="obtained new client token: AADocVpfR9DfRQc0zhKLq72RUmVDAHZ83AkeyDpQwZLJwJpiTUrOi6pRRii1bJrJiYSdvwyYTT4pZ301b0Tv957SyDDlnICQl54uL7UjcrtNsp1T1H+XPO59wc+CIExzFfPKK4z0TTd4zkrBjEZRqpWZmi7H310flQR4neObolG8BGO2Jfa1js24K5gkM1VS9rfPXueD1ic2Pu+Ew1GHfH989fgoFp6DfOAqI5xJxbmDuWruvXYkMy/VTvQ=" Oct 23 18:41:00 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:00 rivo go-librespot[20191]: time="2025-10-23T18:41:00+02:00" level=debug msg="new websocket client" Oct 23 18:41:00 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:41:00 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 23 18:41:00 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 23 18:41:00 rivo volumio[3306]: info: Discovery: Getting this device information Oct 23 18:41:00 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:00 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:00 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 23 18:41:00 rivo go-librespot[20191]: time="2025-10-23T18:41:00+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:00 rivo go-librespot[20191]: time="2025-10-23T18:41:00+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:00 rivo go-librespot[20191]: time="2025-10-23T18:41:00+02:00" level=debug msg="completed challenge" Oct 23 18:41:00 rivo go-librespot[20191]: time="2025-10-23T18:41:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:00 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:41:00 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:00 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:03 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:41:03 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:03 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:41:03 rivo volumio[3306]: (node:3306) 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: 211) Oct 23 18:41:03 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:41:03 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:03 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:03 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:41:03 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:03 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:04 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:04 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 430. Oct 23 18:41:04 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:04 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:04 rivo go-librespot[20210]: Librespot-go daemon starting... Oct 23 18:41:04 rivo go-librespot[20210]: time="2025-10-23T18:41:04+02:00" level=info msg="generated new device id: 715e3efcdfe11925c81748852da6ce3225d30201" Oct 23 18:41:04 rivo go-librespot[20210]: time="2025-10-23T18:41:04+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:04 rivo go-librespot[20210]: time="2025-10-23T18:41:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:41:04 rivo go-librespot[20210]: time="2025-10-23T18:41:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:41:04 rivo go-librespot[20210]: time="2025-10-23T18:41:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:41:04 rivo go-librespot[20210]: time="2025-10-23T18:41:04+02:00" level=debug msg="zeroconf server listening on port 35929" Oct 23 18:41:05 rivo go-librespot[20210]: time="2025-10-23T18:41:05+02:00" level=debug msg="obtained new client token: AADgeyF13BVN6gJz2G1CGPLtttpQLqqZiD0aHuFB+PSOLnJCFE3n1J+8bl4k5ZqcvAtB95TjwUfMpnMAXVQ448JRF3StmtCwfAoMKqLboWyjGvZz5rsxgi+B+gnMwulBVwgumna6r0zrTAw0pYnQg12qcsDObF8ZJATouD0lNMbE2HhPz7qLWm0Pev0QJqJUhsJAgrvWz9n3YTX81yQg6/SKhbFg6q8ckyjLKXDRB5eFAl4gzIUHY1NrJDk=" Oct 23 18:41:05 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 23 18:41:05 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 23 18:41:05 rivo volumio[3306]: info: Discovery: Getting this device information Oct 23 18:41:05 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:05 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:05 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 23 18:41:05 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Oct 23 18:41:05 rivo go-librespot[20210]: time="2025-10-23T18:41:05+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:05 rivo go-librespot[20210]: time="2025-10-23T18:41:05+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:05 rivo go-librespot[20210]: time="2025-10-23T18:41:05+02:00" level=debug msg="completed challenge" Oct 23 18:41:06 rivo go-librespot[20210]: time="2025-10-23T18:41:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:06 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:06 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:06 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:06 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:09 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:09 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 431. Oct 23 18:41:09 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:09 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:09 rivo go-librespot[20253]: Librespot-go daemon starting... Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=info msg="generated new device id: 82975c71274897ac20326b372846dbfc027a888c" Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=debug msg="zeroconf server listening on port 46769" Oct 23 18:41:09 rivo go-librespot[20253]: time="2025-10-23T18:41:09+02:00" level=debug msg="obtained new client token: AABV6VlAuY5RBbOJnUZi5baPuZos9zH/SWwgwhJsDM6rzHNaXhQfrjVk8Tjs1QZa/rv88EvrtGbJQaM/qyav4i5E4mf0+PFsFomyxs0XBNHTjlUHLcLEyiLpUnTzRXgGGXgw9L9ycO8aoKhqHXAw8QZ6KHV0FOKxTkEmYkwAOb4dA3c76q5p/3PpTh/62FbwlI8k/cxboUNgXbtgyzwvUxlr95afILb6yiGqZrQGpDrpk6dUdzwae0co1rc=" Oct 23 18:41:10 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:10 rivo go-librespot[20253]: time="2025-10-23T18:41:10+02:00" level=debug msg="new websocket client" Oct 23 18:41:10 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:41:10 rivo go-librespot[20253]: time="2025-10-23T18:41:10+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Oct 23 18:41:10 rivo go-librespot[20253]: time="2025-10-23T18:41:10+02:00" level=info msg="connected to ap-gew4.spotify.com:443" Oct 23 18:41:10 rivo go-librespot[20253]: time="2025-10-23T18:41:10+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:10 rivo go-librespot[20253]: time="2025-10-23T18:41:10+02:00" level=debug msg="completed challenge" Oct 23 18:41:11 rivo go-librespot[20253]: time="2025-10-23T18:41:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:11 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:11 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:11 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:41:13 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:41:13 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:13 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:41:13 rivo volumio[3306]: (node:3306) 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: 212) Oct 23 18:41:13 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:41:13 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:13 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:13 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:41:14 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:14 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:14 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:14 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 432. Oct 23 18:41:14 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:14 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:14 rivo go-librespot[20283]: Librespot-go daemon starting... Oct 23 18:41:14 rivo go-librespot[20283]: time="2025-10-23T18:41:14+02:00" level=info msg="generated new device id: 70ad60773213ab9b7aa1487eaabce14bd17c9c3e" Oct 23 18:41:14 rivo go-librespot[20283]: time="2025-10-23T18:41:14+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:14 rivo go-librespot[20283]: time="2025-10-23T18:41:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:41:14 rivo go-librespot[20283]: time="2025-10-23T18:41:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:41:14 rivo go-librespot[20283]: time="2025-10-23T18:41:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:41:14 rivo go-librespot[20283]: time="2025-10-23T18:41:14+02:00" level=debug msg="zeroconf server listening on port 46019" Oct 23 18:41:15 rivo go-librespot[20283]: time="2025-10-23T18:41:15+02:00" level=debug msg="obtained new client token: AAC6LSciojkzd8tuI0pz0qOumMgnlAK8iPQoVintNQAfcGgIOjrMw0y3/xh2yMpNe8utDlM4LgToGGoKVrTxZu8VHJF0ihqdn0Ze08MIj0tqxcO/6bmtCgzWd4x/Ps9XwH9wctGwq1M5ttre/o+bdKT0StRTYlIrruvQUO3ig8JCxsQRO5sKy61FruzwAYb8A11vhi0yGtJr6YrC1u3dUXlzpG1XmE81JRt95wH0HaVvpHfnixw0WpUR" Oct 23 18:41:15 rivo go-librespot[20283]: time="2025-10-23T18:41:15+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:15 rivo go-librespot[20283]: time="2025-10-23T18:41:15+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:15 rivo go-librespot[20283]: time="2025-10-23T18:41:15+02:00" level=debug msg="completed challenge" Oct 23 18:41:16 rivo go-librespot[20283]: time="2025-10-23T18:41:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:16 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:16 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:16 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Oct 23 18:41:17 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:17 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:19 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:19 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 433. Oct 23 18:41:19 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:19 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:19 rivo go-librespot[20318]: Librespot-go daemon starting... Oct 23 18:41:19 rivo go-librespot[20318]: time="2025-10-23T18:41:19+02:00" level=info msg="generated new device id: dcf4c2378a84902e08f70813af80d20319610332" Oct 23 18:41:19 rivo go-librespot[20318]: time="2025-10-23T18:41:19+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:19 rivo go-librespot[20318]: time="2025-10-23T18:41:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:41:19 rivo go-librespot[20318]: time="2025-10-23T18:41:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:41:19 rivo go-librespot[20318]: time="2025-10-23T18:41:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:41:19 rivo go-librespot[20318]: time="2025-10-23T18:41:19+02:00" level=debug msg="zeroconf server listening on port 41983" Oct 23 18:41:20 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:20 rivo go-librespot[20318]: time="2025-10-23T18:41:20+02:00" level=debug msg="new websocket client" Oct 23 18:41:20 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:41:20 rivo go-librespot[20318]: time="2025-10-23T18:41:20+02:00" level=debug msg="obtained new client token: AABbxHPn3QkVbzO6/cJtLK57WEZYiSodLsOohb6k8jjx0RFoPT0kHx4AD4ZEDTO9zJ+Bh9urf0SYDzNUA8dOXlQiqa88FtkPVzfdp6i9YZX2ttoANCpO7kjydWGmv5I6KelD5KAmSRF42Qun6alNQi6qMmiXLSCs5S2CDGzw7XvABMyeRJNIr6+Vw0hL5gxD8GqSvyNO96X1B1idhfEf3T3WgHlEB2PbbKxokHQC08thiaXfb0bIrRSr" Oct 23 18:41:20 rivo go-librespot[20318]: time="2025-10-23T18:41:20+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Oct 23 18:41:20 rivo go-librespot[20318]: time="2025-10-23T18:41:20+02:00" level=info msg="connected to ap-gew4.spotify.com:443" Oct 23 18:41:20 rivo go-librespot[20318]: time="2025-10-23T18:41:20+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:21 rivo go-librespot[20318]: time="2025-10-23T18:41:21+02:00" level=debug msg="completed challenge" Oct 23 18:41:21 rivo go-librespot[20318]: time="2025-10-23T18:41:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:21 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:21 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:21 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:41:23 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:41:23 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:23 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:41:23 rivo volumio[3306]: (node:3306) 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: 213) Oct 23 18:41:23 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:41:23 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:23 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:23 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:41:24 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:24 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:24 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:24 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 434. Oct 23 18:41:24 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:24 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:24 rivo go-librespot[20338]: Librespot-go daemon starting... Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=info msg="generated new device id: 519bcc7a07e402f48a5c75236727d45aa6baeea0" Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=debug msg="zeroconf server listening on port 46031" Oct 23 18:41:24 rivo go-librespot[20338]: time="2025-10-23T18:41:24+02:00" level=debug msg="obtained new client token: AABVOp0v0QL2q6KZb7FjtRtw+xqbYUz17a7cWFmjMLNzPJsa1RnHpvIX045E2/dbe2XHArWnGDlv5wFNCri6yHtmeYHVEFf+pmDtREHPBaKpEYBUUIJpm2lQhBLWzzBQuXpoHi16PCQfjtWCTUgf41jo+OciOxQ+A6UfrT4e5hOwltRKseUn3Ex7zLWc7cMuVThEkEi2hq92lS/xN/nLmmweENuOtx24gA5s0koJwef5LQyJkr5mtm+3Nb4=" Oct 23 18:41:25 rivo go-librespot[20338]: time="2025-10-23T18:41:25+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:25 rivo go-librespot[20338]: time="2025-10-23T18:41:25+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:25 rivo go-librespot[20338]: time="2025-10-23T18:41:25+02:00" level=debug msg="completed challenge" Oct 23 18:41:25 rivo go-librespot[20338]: time="2025-10-23T18:41:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:25 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:25 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:26 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100 from 192.168.1.102 UA: Mozilla/5.0 (Linux; Android 11; moto g 5G Build/RZKS31.Q3-25-15-11; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.207 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::volumioGetVisibleSources Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:26 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 23 18:41:26 rivo volumio[3306]: info: Received Get System Info Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 23 18:41:26 rivo volumio[3306]: info: Discovery: Getting this device information Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:26 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:26 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:26 rivo volumio[3306]: info: Listing playlists Oct 23 18:41:26 rivo volumio[3306]: info: CoreCommandRouter::volumioGetQueue Oct 23 18:41:26 rivo volumio[3306]: info: CoreStateMachine::getQueue Oct 23 18:41:26 rivo volumio[3306]: info: CorePlayQueue::getQueue Oct 23 18:41:27 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 23 18:41:27 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:27 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:28 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:28 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 435. Oct 23 18:41:28 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:28 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:28 rivo go-librespot[20364]: Librespot-go daemon starting... Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=info msg="generated new device id: 06d0bbd4c50d271e08f7dc267bf6562eb22f2920" Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=debug msg="zeroconf server listening on port 43799" Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=debug msg="obtained new client token: AABBhzrJRAoQnweR46mLNv8VAHPAfUoWEWvu4ld1ajEI0paRle/0u1a0NHcYi4C8Z7aW2mimY/68wwmhj/eO+UxVWOrxdUDVBZciht+9oORTPVQylvyqQzgRgtTLsXjt3YjInzjoKSPxDkGSmnak0TKHVlETIjJdaN4fIOwhdzNQF6ny9KUwOIyCLZ+80hH/AJRLAMU4RURXJdFciSv+4mU0LLR2E8F76ey+ncp8/YpwAF7o97fJjTxkIKg=" Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 23 18:41:29 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:29 rivo go-librespot[20364]: time="2025-10-23T18:41:29+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:30 rivo go-librespot[20364]: time="2025-10-23T18:41:30+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:30 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:30 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:30 rivo go-librespot[20364]: time="2025-10-23T18:41:30+02:00" level=debug msg="completed challenge" Oct 23 18:41:30 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:30 rivo go-librespot[20364]: time="2025-10-23T18:41:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:30 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:30 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:31 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:31 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:31 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:31 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:31 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:32 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:32 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:32 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:32 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:32 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:32 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:33 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:33 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:33 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:33 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:33 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:33 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 436. Oct 23 18:41:33 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:33 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:33 rivo go-librespot[20425]: Librespot-go daemon starting... Oct 23 18:41:33 rivo go-librespot[20425]: time="2025-10-23T18:41:33+02:00" level=info msg="generated new device id: 16f111d31b8402f639258eaf4ef662001b3c175d" Oct 23 18:41:34 rivo go-librespot[20425]: time="2025-10-23T18:41:34+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - Oct 23 18:41:34 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo go-librespot[20425]: time="2025-10-23T18:41:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 23 18:41:34 rivo go-librespot[20425]: time="2025-10-23T18:41:34+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 23 18:41:34 rivo go-librespot[20425]: time="2025-10-23T18:41:34+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo go-librespot[20425]: time="2025-10-23T18:41:34+02:00" level=debug msg="zeroconf server listening on port 37503" Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo go-librespot[20425]: time="2025-10-23T18:41:34+02:00" level=debug msg="obtained new client token: AAAnKzSXZWJ37FipHr48c76StEAN/i6tQ9NqXxF604rxnBztN8LQSLJjbqn4pwtwHgeXPwLAplRQYiukLeJpShLyScqnvtMtz52RH+KeqN+P/7o6+J5GtHhU/5ZR3vHbXke+ROY35vEE5tQcu60wgMfKetloPpbNM1VbrVMS80M+LjMbU9L+t4kPEHpsj6ZCsP603cwkjDoAzIZifqQDynSWEsw1ak2FQpnqONglu+gyMtqjF9f/eF5DhKg=" Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:34 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo go-librespot[20425]: time="2025-10-23T18:41:35+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:35 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo go-librespot[20425]: time="2025-10-23T18:41:35+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:35 rivo volumio[3306]: info: FusionDsp - undefined Oct 23 18:41:35 rivo volumio[3306]: Upnp client error: Error: This socket has been ended by the other party Oct 23 18:41:35 rivo go-librespot[20425]: time="2025-10-23T18:41:35+02:00" level=debug msg="new websocket client" Oct 23 18:41:35 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:41:35 rivo volumio[3306]: Upnp client error: Error: This socket has been ended by the other party Oct 23 18:41:35 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 23 18:41:35 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 23 18:41:35 rivo volumio[3306]: info: Discovery: Getting this device information Oct 23 18:41:35 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:35 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:35 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 23 18:41:35 rivo go-librespot[20425]: time="2025-10-23T18:41:35+02:00" level=debug msg="completed challenge" Oct 23 18:41:35 rivo go-librespot[20425]: time="2025-10-23T18:41:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:35 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:35 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:35 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:41:36 rivo volumio[3306]: verbose: New Socket.io Connection to 192.168.1.100:3000 from 192.168.1.102 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Oct 23 18:41:37 rivo volumio[3306]: info: [1761237697537] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=0 Oct 23 18:41:38 rivo volumio[3306]: info: [1761237698264] [RadioParadise] received new metadata: {"time":137,"artist":"Green Day","title":"Good Riddance (Time Of Your Life)","album":"nimrod.","year":"1997","cover":"https://img.radioparadise.com/covers/l/B000002NIH.jpg","cover_med":"https://img.radioparadise.com/covers/m/B000002NIH.jpg","cover_small":"https://img.radioparadise.com/covers/s/B000002NIH.jpg"} Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::servicePushState Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B000002NIH.jpg","uri":"https://stream.radioparadise.com/flac","name":"Good Riddance (Time Of Your Life)","title":"Good Riddance (Time Of Your Life)","artist":"Green Day","album":"nimrod.","streaming":true,"disableUiControls":true,"duration":142,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 23 18:41:38 rivo volumio[3306]: verbose: CURRENT POSITION 0 Oct 23 18:41:38 rivo volumio[3306]: info: CoreStateMachine::syncState stateService play Oct 23 18:41:38 rivo volumio[3306]: info: CoreStateMachine::syncState currentStatus play Oct 23 18:41:38 rivo volumio[3306]: info: Received an update from plugin. extracting info from payload Oct 23 18:41:38 rivo volumio[3306]: info: CoreStateMachine::pushState Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::volumioPushState Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: info: CoreStateMachine::pushState Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::volumioPushState Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: info: [1761237698338] [RadioParadise] setting new timer with duration of 142000 seconds. Oct 23 18:41:38 rivo volumio[3306]: info: Getting Spotify volume Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 1 Oct 23 18:41:38 rivo volumio[3306]: info: [LastFM] Current track has sufficient metadata: title (Good Riddance (Time Of Your Life)) and artist (Green Day) passed on explicitly Oct 23 18:41:38 rivo volumio[3306]: (node:3306) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:38 rivo volumio[3306]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Oct 23 18:41:38 rivo volumio[3306]: (node:3306) 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: 214) Oct 23 18:41:38 rivo volumio[3306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 23 18:41:38 rivo volumio[3306]: info: CoreCommandRouter::volumioGetState Oct 23 18:41:38 rivo volumio[3306]: info: CorePlayQueue::getTrack 0 Oct 23 18:41:38 rivo volumio[3306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 23 18:41:38 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:38 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:38 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:38 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 437. Oct 23 18:41:38 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:38 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:38 rivo go-librespot[20448]: Librespot-go daemon starting... Oct 23 18:41:38 rivo go-librespot[20448]: time="2025-10-23T18:41:38+02:00" level=info msg="generated new device id: b825ef395af5cabf3e0a987030b3e049d820f39c" Oct 23 18:41:38 rivo go-librespot[20448]: time="2025-10-23T18:41:38+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=debug msg="zeroconf server listening on port 45157" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=debug msg="obtained new client token: AAD05VzXvziu9hqgRxIqRNcnNAy8q6lrjIwOBPPprKk30j9moWF/f+KtlNkQP4+nR38gV3Zbytks8ywlDq34JDwP+mzjH9eG77enFbK0IC6ufXitBYQR5Y8i9skJNc29ksOE12199yL3OaQmLZdVHbBekZzdFhd1eXSGV7decjfalufamIVQUNi0uFDKzFm0fIcPrmpf8E3Kj9875DjfdZRLEE5bAchD7cVrpgek2URNm7J1YsKGzfCKZcU=" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:39 rivo go-librespot[20448]: time="2025-10-23T18:41:39+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:40 rivo volumio[3306]: info: Executing endpoint metavolumio Oct 23 18:41:40 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 23 18:41:40 rivo volumio[3306]: info: Executing endpoint metavolumio Oct 23 18:41:40 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 23 18:41:40 rivo volumio[3306]: info: Executing endpoint metavolumio Oct 23 18:41:40 rivo volumio[3306]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 23 18:41:40 rivo go-librespot[20448]: time="2025-10-23T18:41:40+02:00" level=debug msg="completed challenge" Oct 23 18:41:40 rivo go-librespot[20448]: time="2025-10-23T18:41:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:40 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:40 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:41 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:41 rivo volumio[3306]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 23 18:41:43 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:43 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 438. Oct 23 18:41:43 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:43 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:43 rivo go-librespot[20485]: Librespot-go daemon starting... Oct 23 18:41:43 rivo go-librespot[20485]: time="2025-10-23T18:41:43+02:00" level=info msg="generated new device id: bd39ecb6486f29789859ea233aacd5e47452ae78" Oct 23 18:41:43 rivo go-librespot[20485]: time="2025-10-23T18:41:43+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="zeroconf server listening on port 34877" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="obtained new client token: AAD9gBmn0B2Ih7fHi14AZY4LPeuXP4qagnRsC3rSK2CdwPEuu7tKrfSQUjvq/p1mzAJdZSXFlHh/86ONVrTVUn3paMWFqDbMQpBbCm53kArWEbpE9NUAXs2R7CtzTrEAuJ1csFHaw8gHvd7X3OAfMKRg0U9cqWmdSwAd58ObVgrkyyapPrkVB7KxTxw6WxSwg13wIIEexeFAyaC/5YyoNTbnpELhXLmR6BGzXg5NWQcwkrBtu7w9BBgEYKU=" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="completed keyexchange" Oct 23 18:41:44 rivo volumio[3306]: info: Initializing connection to go-librespot Websocket Oct 23 18:41:44 rivo go-librespot[20485]: time="2025-10-23T18:41:44+02:00" level=debug msg="new websocket client" Oct 23 18:41:44 rivo volumio[3306]: info: Connection to go-librespot Websocket established Oct 23 18:41:45 rivo go-librespot[20485]: time="2025-10-23T18:41:45+02:00" level=debug msg="completed challenge" Oct 23 18:41:45 rivo go-librespot[20485]: time="2025-10-23T18:41:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Oct 23 18:41:45 rivo volumio[3306]: info: Connection to go-librespot Websocket closed Oct 23 18:41:45 rivo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 23 18:41:45 rivo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 23 18:41:47 rivo volumio[3306]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 23 18:41:47 rivo volumio[3306]: TypeError: Cannot read property '@' of undefined Oct 23 18:41:47 rivo volumio[3306]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Oct 23 18:41:47 rivo volumio[3306]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Oct 23 18:41:47 rivo volumio[3306]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) Oct 23 18:41:47 rivo volumio[3306]: at Parser.emit (events.js:400:28) Oct 23 18:41:47 rivo volumio[3306]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) Oct 23 18:41:47 rivo volumio[3306]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) Oct 23 18:41:47 rivo volumio[3306]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) Oct 23 18:41:47 rivo volumio[3306]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) Oct 23 18:41:47 rivo volumio[3306]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) Oct 23 18:41:47 rivo volumio[3306]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) Oct 23 18:41:47 rivo volumio[3306]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) Oct 23 18:41:47 rivo volumio[3306]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Oct 23 18:41:47 rivo volumio[3306]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Oct 23 18:41:47 rivo volumio[3306]: at IncomingMessage.emit (events.js:412:35) Oct 23 18:41:47 rivo volumio[3306]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 23 18:41:47 rivo volumio[3306]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 23 18:41:47 rivo volumio[3306]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 23 18:41:48 rivo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 23 18:41:48 rivo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 439. Oct 23 18:41:48 rivo systemd[1]: Stopped go-librespot Daemon. Oct 23 18:41:48 rivo systemd[1]: Started go-librespot Daemon. Oct 23 18:41:48 rivo go-librespot[20510]: Librespot-go daemon starting... Oct 23 18:41:48 rivo go-librespot[20510]: time="2025-10-23T18:41:48+02:00" level=info msg="generated new device id: a00a914ecdad68cf267775d5dbe620dd722aeb2d" Oct 23 18:41:48 rivo go-librespot[20510]: time="2025-10-23T18:41:48+02:00" level=debug msg="stored credentials found for 31ufjgzm7ki5qunbvnwotliejbxm" Oct 23 18:41:48 rivo sudo[20518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-23 18:40 Oct 23 18:41:48 rivo sudo[20518]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:43:09 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="fc7d09bc07ffd188bff4808d8f79c746"