-- Logs begin at Wed 2025-11-05 20:08:25 GMT, end at Wed 2025-11-05 22:05:26 GMT. -- Nov 05 22:04:00 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:00 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304373. Nov 05 22:04:00 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:00 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:00 volumio go-librespot[26511]: Librespot-go daemon starting... Nov 05 22:04:00 volumio go-librespot[26511]: time="2025-11-05T22:04:00Z" level=info msg="generated new device id: cec63c4a83369f4012c025edbd65f6ce97da7406" Nov 05 22:04:00 volumio go-librespot[26511]: time="2025-11-05T22:04:00Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:00 volumio go-librespot[26511]: time="2025-11-05T22:04:00Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:03 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:03 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304374. Nov 05 22:04:04 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:04 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:04 volumio go-librespot[26556]: Librespot-go daemon starting... Nov 05 22:04:04 volumio go-librespot[26556]: time="2025-11-05T22:04:04Z" level=info msg="generated new device id: 358eb18b9c84f465504558904c1ea9333f9a852f" Nov 05 22:04:04 volumio go-librespot[26556]: time="2025-11-05T22:04:04Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:04 volumio go-librespot[26556]: time="2025-11-05T22:04:04Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:06 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:06 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304375. Nov 05 22:04:07 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:07 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:07 volumio go-librespot[26573]: Librespot-go daemon starting... Nov 05 22:04:07 volumio go-librespot[26573]: time="2025-11-05T22:04:07Z" level=info msg="generated new device id: e17f5edad272ff77f77a3380c8f2344e72f6f0b7" Nov 05 22:04:07 volumio go-librespot[26573]: time="2025-11-05T22:04:07Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:07 volumio go-librespot[26573]: time="2025-11-05T22:04:07Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:09 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:09 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304376. Nov 05 22:04:10 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:10 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:10 volumio go-librespot[26595]: Librespot-go daemon starting... Nov 05 22:04:10 volumio go-librespot[26595]: time="2025-11-05T22:04:10Z" level=info msg="generated new device id: f1c16b32fc596b3fe5a9da88fbfec6757f66f861" Nov 05 22:04:10 volumio go-librespot[26595]: time="2025-11-05T22:04:10Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:10 volumio go-librespot[26595]: time="2025-11-05T22:04:10Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:11 volumio ntpd[6967]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 05 22:04:12 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:12 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304377. Nov 05 22:04:13 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:13 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:13 volumio go-librespot[26602]: Librespot-go daemon starting... Nov 05 22:04:13 volumio go-librespot[26602]: time="2025-11-05T22:04:13Z" level=info msg="generated new device id: cb93a4b6f7476045061db7f32ce0624698dceb1e" Nov 05 22:04:13 volumio go-librespot[26602]: time="2025-11-05T22:04:13Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:13 volumio go-librespot[26602]: time="2025-11-05T22:04:13Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:15 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:15 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304378. Nov 05 22:04:17 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:17 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:17 volumio go-librespot[26610]: Librespot-go daemon starting... Nov 05 22:04:17 volumio go-librespot[26610]: time="2025-11-05T22:04:17Z" level=info msg="generated new device id: aa3d583ef9b5931116181baad8ba32e31ad7ce2a" Nov 05 22:04:17 volumio go-librespot[26610]: time="2025-11-05T22:04:17Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:17 volumio go-librespot[26610]: time="2025-11-05T22:04:17Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:18 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:18 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304379. Nov 05 22:04:20 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:20 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:20 volumio go-librespot[26646]: Librespot-go daemon starting... Nov 05 22:04:20 volumio go-librespot[26646]: time="2025-11-05T22:04:20Z" level=info msg="generated new device id: eb3689730989b5b234a86b262aa519a091492793" Nov 05 22:04:20 volumio go-librespot[26646]: time="2025-11-05T22:04:20Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:20 volumio go-librespot[26646]: time="2025-11-05T22:04:20Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:21 volumio ntpd[6967]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 05 22:04:21 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:21 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304380. Nov 05 22:04:23 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:23 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:23 volumio go-librespot[26653]: Librespot-go daemon starting... Nov 05 22:04:23 volumio go-librespot[26653]: time="2025-11-05T22:04:23Z" level=info msg="generated new device id: 4ae2c6404e34873d48e0f90d7f32c61c8af8c370" Nov 05 22:04:23 volumio go-librespot[26653]: time="2025-11-05T22:04:23Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:23 volumio go-librespot[26653]: time="2025-11-05T22:04:23Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:24 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:24 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304381. Nov 05 22:04:26 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:26 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:26 volumio go-librespot[26661]: Librespot-go daemon starting... Nov 05 22:04:26 volumio go-librespot[26661]: time="2025-11-05T22:04:26Z" level=info msg="generated new device id: 2218e3c12ca49cc26ba8b4c44e3b15b476d34a76" Nov 05 22:04:26 volumio go-librespot[26661]: time="2025-11-05T22:04:26Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:26 volumio go-librespot[26661]: time="2025-11-05T22:04:26Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:27 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:27 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:28 volumio ntpd[6967]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 05 22:04:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304382. Nov 05 22:04:30 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:30 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:30 volumio go-librespot[26682]: Librespot-go daemon starting... Nov 05 22:04:30 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:30 volumio go-librespot[26682]: time="2025-11-05T22:04:30Z" level=info msg="generated new device id: c8c969310050047aca0f918589e698fc45ed72e3" Nov 05 22:04:30 volumio go-librespot[26682]: time="2025-11-05T22:04:30Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:30 volumio go-librespot[26682]: time="2025-11-05T22:04:30Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:30 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: read ECONNRESET Nov 05 22:04:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:32 volumio ntpd[6967]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 05 22:04:33 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:33 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304383. Nov 05 22:04:33 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:33 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:33 volumio go-librespot[26695]: Librespot-go daemon starting... Nov 05 22:04:33 volumio go-librespot[26695]: time="2025-11-05T22:04:33Z" level=info msg="generated new device id: 39cf71a053adafd46eefcc9c1cb2085547e24125" Nov 05 22:04:33 volumio go-librespot[26695]: time="2025-11-05T22:04:33Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:33 volumio go-librespot[26695]: time="2025-11-05T22:04:33Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:36 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:36 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304384. Nov 05 22:04:36 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:36 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:36 volumio go-librespot[26703]: Librespot-go daemon starting... Nov 05 22:04:36 volumio go-librespot[26703]: time="2025-11-05T22:04:36Z" level=info msg="generated new device id: d780989e3f3b89d0b028d5f91b7f6f336a6ab897" Nov 05 22:04:36 volumio go-librespot[26703]: time="2025-11-05T22:04:36Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:36 volumio go-librespot[26703]: time="2025-11-05T22:04:36Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:39 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:39 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304385. Nov 05 22:04:39 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:39 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:39 volumio go-librespot[26714]: Librespot-go daemon starting... Nov 05 22:04:39 volumio go-librespot[26714]: time="2025-11-05T22:04:39Z" level=info msg="generated new device id: 74f280a952bad6788f40c1c6e6bc618376362258" Nov 05 22:04:39 volumio go-librespot[26714]: time="2025-11-05T22:04:39Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:39 volumio go-librespot[26714]: time="2025-11-05T22:04:39Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:42 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:42 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304386. Nov 05 22:04:43 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:43 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:43 volumio go-librespot[26735]: Librespot-go daemon starting... Nov 05 22:04:43 volumio go-librespot[26735]: time="2025-11-05T22:04:43Z" level=info msg="generated new device id: 2fb4c6c8a9870561dc58cba46f17098334296975" Nov 05 22:04:43 volumio go-librespot[26735]: time="2025-11-05T22:04:43Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:43 volumio go-librespot[26735]: time="2025-11-05T22:04:43Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:45 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:45 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304387. Nov 05 22:04:46 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:46 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:46 volumio go-librespot[26750]: Librespot-go daemon starting... Nov 05 22:04:46 volumio go-librespot[26750]: time="2025-11-05T22:04:46Z" level=info msg="generated new device id: 69aa8eb071f980d6be0eafd096cc74f5e1c6ab84" Nov 05 22:04:46 volumio go-librespot[26750]: time="2025-11-05T22:04:46Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:46 volumio go-librespot[26750]: time="2025-11-05T22:04:46Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:48 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:48 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304388. Nov 05 22:04:49 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:49 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:49 volumio go-librespot[26757]: Librespot-go daemon starting... Nov 05 22:04:49 volumio go-librespot[26757]: time="2025-11-05T22:04:49Z" level=info msg="generated new device id: 5f0de2e5657829a3347a674381bea057423328e8" Nov 05 22:04:49 volumio go-librespot[26757]: time="2025-11-05T22:04:49Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:49 volumio go-librespot[26757]: time="2025-11-05T22:04:49Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:51 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:51 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304389. Nov 05 22:04:52 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:52 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:52 volumio go-librespot[26779]: Librespot-go daemon starting... Nov 05 22:04:52 volumio go-librespot[26779]: time="2025-11-05T22:04:52Z" level=info msg="generated new device id: be271ed73e8a93c91493e4d0be1b0e8d0729057b" Nov 05 22:04:52 volumio go-librespot[26779]: time="2025-11-05T22:04:52Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:52 volumio go-librespot[26779]: time="2025-11-05T22:04:52Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:54 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:54 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304390. Nov 05 22:04:56 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:56 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:56 volumio go-librespot[26786]: Librespot-go daemon starting... Nov 05 22:04:56 volumio go-librespot[26786]: time="2025-11-05T22:04:56Z" level=info msg="generated new device id: d9b62d59d60c0fdc01ab06f1dcce50cd7b353b05" Nov 05 22:04:56 volumio go-librespot[26786]: time="2025-11-05T22:04:56Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:56 volumio go-librespot[26786]: time="2025-11-05T22:04:56Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:04:57 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:04:57 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:04:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:04:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304391. Nov 05 22:04:59 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:04:59 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:04:59 volumio go-librespot[26804]: Librespot-go daemon starting... Nov 05 22:04:59 volumio go-librespot[26804]: time="2025-11-05T22:04:59Z" level=info msg="generated new device id: 2cb18eb1d250d3837cbe325fa08d716f9e4a9289" Nov 05 22:04:59 volumio go-librespot[26804]: time="2025-11-05T22:04:59Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:04:59 volumio go-librespot[26804]: time="2025-11-05T22:04:59Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:04:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:04:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:05:00 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:00 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:05:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304392. Nov 05 22:05:02 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:05:02 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:05:02 volumio go-librespot[26826]: Librespot-go daemon starting... Nov 05 22:05:02 volumio go-librespot[26826]: time="2025-11-05T22:05:02Z" level=info msg="generated new device id: cd4865ab088fa5cfb3ade8c3fed84bbbad3cfd42" Nov 05 22:05:02 volumio go-librespot[26826]: time="2025-11-05T22:05:02Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:05:02 volumio go-librespot[26826]: time="2025-11-05T22:05:02Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:05:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:05:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:05:03 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:03 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:05:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304393. Nov 05 22:05:05 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:05:05 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:05:05 volumio go-librespot[26871]: Librespot-go daemon starting... Nov 05 22:05:05 volumio go-librespot[26871]: time="2025-11-05T22:05:05Z" level=info msg="generated new device id: bf46a89856bb01176d74e70e345a19a9b616cd4d" Nov 05 22:05:05 volumio go-librespot[26871]: time="2025-11-05T22:05:05Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:05:05 volumio go-librespot[26871]: time="2025-11-05T22:05:05Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:05:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:05:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:05:06 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:06 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:05:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304394. Nov 05 22:05:09 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:05:09 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:05:09 volumio go-librespot[26878]: Librespot-go daemon starting... Nov 05 22:05:09 volumio go-librespot[26878]: time="2025-11-05T22:05:09Z" level=info msg="generated new device id: 493a86a1ad309ea0831c7f711ef1951b6635bfc4" Nov 05 22:05:09 volumio go-librespot[26878]: time="2025-11-05T22:05:09Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:05:09 volumio go-librespot[26878]: time="2025-11-05T22:05:09Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:05:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:05:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:05:09 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:09 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:12 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:12 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:05:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304395. Nov 05 22:05:12 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:05:12 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:05:12 volumio go-librespot[26906]: Librespot-go daemon starting... Nov 05 22:05:12 volumio go-librespot[26906]: time="2025-11-05T22:05:12Z" level=info msg="generated new device id: 4fcc718ae65f53e504671132e1a7dd25c24675e3" Nov 05 22:05:12 volumio go-librespot[26906]: time="2025-11-05T22:05:12Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:05:12 volumio go-librespot[26906]: time="2025-11-05T22:05:12Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:05:15 volumio ntpd[6967]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 05 22:05:15 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:15 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:05:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304396. Nov 05 22:05:15 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:05:15 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:05:15 volumio go-librespot[26914]: Librespot-go daemon starting... Nov 05 22:05:15 volumio go-librespot[26914]: time="2025-11-05T22:05:15Z" level=info msg="generated new device id: 988c2e28d9feb5876945c70331c1bf1b0d83b5b9" Nov 05 22:05:15 volumio go-librespot[26914]: time="2025-11-05T22:05:15Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:05:15 volumio go-librespot[26914]: time="2025-11-05T22:05:15Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Nov 05 22:05:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 05 22:05:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 05 22:05:17 volumio ntpd[6967]: ntpd exiting on signal 15 (Terminated) Nov 05 22:05:17 volumio systemd[1]: Stopping Network Time Service... Nov 05 22:05:17 volumio systemd[1]: ntp.service: Succeeded. Nov 05 22:05:17 volumio systemd[1]: Stopped Network Time Service. Nov 05 22:05:17 volumio systemd[1]: Starting Network Time Service... Nov 05 22:05:17 volumio ntpd[26986]: ntpd 4.2.8p12@1.3728-o (1): Starting Nov 05 22:05:17 volumio ntpd[26986]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Nov 05 22:05:17 volumio systemd[1]: Started Network Time Service. Nov 05 22:05:17 volumio ntpd[26992]: proto: precision = 0.791 usec (-20) Nov 05 22:05:17 volumio ntpd[26992]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Nov 05 22:05:17 volumio ntpd[26992]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 05 22:05:17 volumio ntpd[26992]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1044 days ago Nov 05 22:05:17 volumio ntpd[26992]: Listen and drop on 0 v6wildcard [::]:123 Nov 05 22:05:17 volumio ntpd[26992]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Nov 05 22:05:17 volumio ntpd[26992]: Listen normally on 2 lo 127.0.0.1:123 Nov 05 22:05:17 volumio ntpd[26992]: Listen normally on 3 eth0 192.168.1.235:123 Nov 05 22:05:17 volumio ntpd[26992]: Listening on routing socket on fd #20 for interface updates Nov 05 22:05:17 volumio ntpd[26992]: kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized Nov 05 22:05:17 volumio ntpd[26992]: kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized Nov 05 22:05:18 volumio ntpd[26992]: Soliciting pool server 193.57.144.50 Nov 05 22:05:18 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:18 volumio volumio[9526]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 05 22:05:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 05 22:05:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304397. Nov 05 22:05:18 volumio systemd[1]: Stopped go-librespot Daemon. Nov 05 22:05:18 volumio systemd[1]: Started go-librespot Daemon. Nov 05 22:05:18 volumio go-librespot[26997]: Librespot-go daemon starting... Nov 05 22:05:18 volumio go-librespot[26997]: time="2025-11-05T22:05:18Z" level=info msg="generated new device id: 7044a85ea8320bd012a1613041fc43853a853b02" Nov 05 22:05:18 volumio go-librespot[26997]: time="2025-11-05T22:05:18Z" level=debug msg="stored credentials found for sophiegoldhill" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="zeroconf server listening on port 34445" Nov 05 22:05:19 volumio ntpd[26992]: Soliciting pool server 213.5.132.231 Nov 05 22:05:19 volumio ntpd[26992]: Soliciting pool server 217.154.37.71 Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="obtained new client token: AABeQOQNrkqF0/4PKvivrG+pt7X9MT3EiuOh/k5LhmAuQ5qne5plN2Ilgsc+1ySnuCPG9dwLrMzbPVhHF7F8FZ9i+z2KmMEUqYkfGzGcUfs+XH9ht6ZBAwWbF7SRniOaN8DMOWPyxqCNs9bVJiR33NnRmjH2UQExD7Su5v8WU3SmGVAe1jsPRZfJY7KcvJ8bhzoPJT96W0w5NtjMIBp9rn4kceaWJe6HOERY7pwzp2YpUZ1kRIAecqyKx4maIMQ=" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=info msg="connected to ap-gew1.spotify.com:4070" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="completed keyexchange" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="completed challenge" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="authenticated as sophiegoldhill" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="authenticated as sophiegoldhill" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="dealer connection opened" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="initializing zeroconf session, username: sophiegoldhill" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="autoplay enabled: false" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="received connection id: MjViZWZjZWYtZWM4ZC00NjYwLTk0Y2YtMzJkN2Y1ODBkYTdkK2RlYWxlcit0Y3A6Ly8wYWNhNDA1Yi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNUFBNTFERUM1MzU2MTU5QTQ0NThBRTgwM0IxNTNDRUZFQ0JENDVFMUI3RDcwRkEwNzIwRDREMTVEMTFENzQxOQ==" Nov 05 22:05:19 volumio go-librespot[26997]: time="2025-11-05T22:05:19Z" level=debug msg="put connect state because NEW_DEVICE" Nov 05 22:05:20 volumio ntpd[26992]: Soliciting pool server 172.237.96.114 Nov 05 22:05:20 volumio ntpd[26992]: Soliciting pool server 162.159.200.123 Nov 05 22:05:20 volumio ntpd[26992]: Soliciting pool server 217.154.60.177 Nov 05 22:05:21 volumio ntpd[26992]: Soliciting pool server 162.159.200.1 Nov 05 22:05:21 volumio ntpd[26992]: Soliciting pool server 129.250.35.250 Nov 05 22:05:21 volumio ntpd[26992]: Soliciting pool server 176.58.127.131 Nov 05 22:05:21 volumio ntpd[26992]: Soliciting pool server 178.79.158.157 Nov 05 22:05:21 volumio volumio[9526]: info: Initializing connection to go-librespot Websocket Nov 05 22:05:21 volumio go-librespot[26997]: time="2025-11-05T22:05:21Z" level=debug msg="new websocket client" Nov 05 22:05:21 volumio volumio[9526]: info: Connection to go-librespot Websocket established Nov 05 22:05:22 volumio ntpd[26992]: Soliciting pool server 178.79.184.152 Nov 05 22:05:22 volumio ntpd[26992]: Soliciting pool server 109.74.192.36 Nov 05 22:05:22 volumio ntpd[26992]: Soliciting pool server 85.199.214.100 Nov 05 22:05:23 volumio ntpd[26992]: Soliciting pool server 176.58.115.34 Nov 05 22:05:23 volumio ntpd[26992]: Soliciting pool server 85.199.214.102 Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin bluetooth to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin multiroom to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin metavolumio to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin cd_controller to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 05 22:05:23 volumio volumio[9526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 05 22:05:23 volumio volumio[9526]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 05 22:05:23 volumio volumio[9526]: info: Starting MyVolumio Remote Streaming Endpoints Nov 05 22:05:23 volumio volumio[9526]: info: MyVolumio login type: Token Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 05 22:05:23 volumio volumio[9526]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 05 22:05:24 volumio ntpd[26992]: Soliciting pool server 80.82.245.120 Nov 05 22:05:24 volumio ntpd[26992]: Soliciting pool server 2a01:7e00::f03c:94ff:fee2:9c69 Nov 05 22:05:24 volumio volumio[9526]: info: Starting Streaming Service Transparent Proxy Nov 05 22:05:24 volumio volumio[9526]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 05 22:05:24 volumio volumio[9526]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 05 22:05:24 volumio volumio[9526]: info: Streaming services startup Nov 05 22:05:24 volumio volumio[9526]: info: Starting Streaming Daemon Nov 05 22:05:24 volumio sudo[27028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 05 22:05:24 volumio sudo[27028]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 05 22:05:24 volumio sudo[27028]: pam_unix(sudo:session): session closed for user root Nov 05 22:05:24 volumio volumio[9526]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 05 22:05:24 volumio volumio[9526]: info: Getting Spotify volume Nov 05 22:05:24 volumio volumio[9526]: error: Cannot start Volumio Streaming Daemon Nov 05 22:05:24 volumio volumio[9526]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 05 22:05:24 volumio volumio[9526]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 05 22:05:24 volumio volumio[9526]: info: Spotify volume: 100 Nov 05 22:05:24 volumio volumio[9526]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 05 22:05:24 volumio volumio[9526]: info: CoreCommandRouter::volumioGetState Nov 05 22:05:24 volumio volumio[9526]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 05 22:05:24 volumio volumio[9526]: SPOTIFY: SPOTIFY VOLUME 100 Nov 05 22:05:24 volumio volumio[9526]: SPOTIFY: VOLUMIO VOLUME 30 Nov 05 22:05:24 volumio volumio[9526]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 05 22:05:24 volumio volumio[9526]: info: Setting Spotify Volume from Volumio: 30 Nov 05 22:05:24 volumio volumio[9526]: error: MyVolumio Custom Token format not valid, refreshing it Nov 05 22:05:24 volumio volumio[9526]: STREAMING PROXY: Starting server on port 3245 Nov 05 22:05:24 volumio volumio[9526]: Node JS runtime: 14 Nov 05 22:05:24 volumio volumio[9526]: info: MyVolumio login type: Token Nov 05 22:05:25 volumio volumio[9526]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 05 22:05:25 volumio volumio[9526]: info: MyVolumio token set successfully Nov 05 22:05:25 volumio volumio[9526]: info: MYVOLUMIO: Adding device Nov 05 22:05:25 volumio volumio[9526]: info: MYVOLUMIO: Evaluating Server Nov 05 22:05:26 volumio volumio[9526]: SPOTIFY: SETTING SPOTIFY VOLUME 30 Nov 05 22:05:26 volumio volumio[9526]: info: Sending Spotify command with payload to local API: /player/volume Nov 05 22:05:26 volumio volumio[9526]: info: MyVolumio status changed Nov 05 22:05:26 volumio volumio[9526]: info: Streaming services startup Nov 05 22:05:26 volumio volumio[9526]: info: Starting Streaming Daemon Nov 05 22:05:26 volumio volumio[9526]: info: Removing browser output: myVolumio user plan is not superstar Nov 05 22:05:26 volumio volumio[9526]: info: Removing audio output: Nov 05 22:05:26 volumio volumio[9526]: info: Stoppping Tunnel 1 Nov 05 22:05:26 volumio sudo[27056]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 05 22:05:26 volumio sudo[27056]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 05 22:05:25 volumio ntpd[26992]: receive: Unexpected origin timestamp 0xecb648a6.13846ee3 does not match aorg 0000000000.00000000 from server@178.79.184.152 xmt 0xecb648a5.ec4d246b Nov 05 22:05:25 volumio ntpd[26992]: receive: Unexpected origin timestamp 0xecb648a6.1389aa70 does not match aorg 0000000000.00000000 from server@217.154.37.71 xmt 0xecb648a5.ecb24b20 Nov 05 22:05:25 volumio systemd[1]: Starting Daily apt download activities... Nov 05 22:05:25 volumio ntpd[26992]: receive: Unexpected origin timestamp 0xecb648a6.138aa4ab does not match aorg 0000000000.00000000 from server@213.5.132.231 xmt 0xecb648a5.ecc30392 Nov 05 22:05:25 volumio go-librespot[26997]: time="2025-11-05T22:05:25Z" level=debug msg="update volume to 19660/65535" Nov 05 22:05:25 volumio sudo[27061]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 05 22:05:25 volumio sudo[27061]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 05 22:05:25 volumio sudo[27056]: pam_unix(sudo:session): session closed for user root Nov 05 22:05:25 volumio volumio[9526]: error: Cannot start Volumio Streaming Daemon Nov 05 22:05:25 volumio volumio[9526]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 05 22:05:25 volumio volumio[9526]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 05 22:05:25 volumio sudo[27061]: pam_unix(sudo:session): session closed for user root Nov 05 22:05:25 volumio volumio[9526]: info: Remote SSH Stopped Nov 05 22:05:25 volumio volumio[9526]: error: Failed to ping endpoint us3.myvolumio.org : unknown error Nov 05 22:05:25 volumio volumio[9526]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 05 22:05:25 volumio volumio[9526]: Error: Unable to resolve or reject the same promise twice Nov 05 22:05:25 volumio volumio[9526]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Nov 05 22:05:25 volumio volumio[9526]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Nov 05 22:05:25 volumio volumio[9526]: at Socket.emit (events.js:412:35) Nov 05 22:05:25 volumio volumio[9526]: at endReadableNT (internal/streams/readable.js:1333:12) Nov 05 22:05:25 volumio volumio[9526]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Nov 05 22:05:25 volumio volumio[9526]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 05 22:05:25 volumio go-librespot[26997]: time="2025-11-05T22:05:25Z" level=debug msg="put connect state because VOLUME_CHANGED" Nov 05 22:05:25 volumio go-librespot[26997]: time="2025-11-05T22:05:25Z" level=trace msg="emitting websocket event: volume" Nov 05 22:05:26 volumio sudo[27117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-05 22:04 Nov 05 22:05:26 volumio sudo[27117]: 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="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 29 Jul 2025 01:38:55 PM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="odroidn2" VOLUMIO_DEVICENAME="Odroid-N2" VOLUMIO_HASH="7ccd4ec723650356901df6b4b03e93ae"