-- Logs begin at Fri 2024-10-25 09:12:45 +03, end at Fri 2024-10-25 09:25:47 +03. -- Oct 25 09:24:00 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:00 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 198. Oct 25 09:24:01 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:01 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:01 volumio go-librespot[3689]: Librespot-go daemon starting... Oct 25 09:24:01 volumio go-librespot[3689]: time="2024-10-25T09:24:01+03:00" level=info msg="generated new device id: 48504e8c3c96063de2512206142c40f38aa592f8" Oct 25 09:24:01 volumio go-librespot[3689]: time="2024-10-25T09:24:01+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:01 volumio go-librespot[3689]: time="2024-10-25T09:24:01+03:00" 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" Oct 25 09:24:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:03 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:03 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 199. Oct 25 09:24:04 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:04 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:04 volumio go-librespot[3696]: Librespot-go daemon starting... Oct 25 09:24:04 volumio go-librespot[3696]: time="2024-10-25T09:24:04+03:00" level=info msg="generated new device id: f24750ec96f601aae8e37c9b0ddb33454d94dec1" Oct 25 09:24:04 volumio go-librespot[3696]: time="2024-10-25T09:24:04+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:04 volumio go-librespot[3696]: time="2024-10-25T09:24:04+03:00" 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" Oct 25 09:24:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:06 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:06 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 200. Oct 25 09:24:07 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:07 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:07 volumio go-librespot[3704]: Librespot-go daemon starting... Oct 25 09:24:07 volumio go-librespot[3704]: time="2024-10-25T09:24:07+03:00" level=info msg="generated new device id: 7cbe2d885a65b318d70b6f1b7b8c2c553c074a7a" Oct 25 09:24:07 volumio go-librespot[3704]: time="2024-10-25T09:24:07+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:07 volumio go-librespot[3704]: time="2024-10-25T09:24:07+03:00" 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" Oct 25 09:24:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:09 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:09 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 201. Oct 25 09:24:10 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:11 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:11 volumio go-librespot[3711]: Librespot-go daemon starting... Oct 25 09:24:11 volumio go-librespot[3711]: time="2024-10-25T09:24:11+03:00" level=info msg="generated new device id: 5e41041f1bb07196d30bc8f9df8c4f92d0dccd12" Oct 25 09:24:11 volumio go-librespot[3711]: time="2024-10-25T09:24:11+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:11 volumio go-librespot[3711]: time="2024-10-25T09:24:11+03:00" 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" Oct 25 09:24:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:12 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:12 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 202. Oct 25 09:24:14 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:14 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:14 volumio go-librespot[3719]: Librespot-go daemon starting... Oct 25 09:24:14 volumio go-librespot[3719]: time="2024-10-25T09:24:14+03:00" level=info msg="generated new device id: 9e3cbba62bcae45605bddb52eecccd91053ce3fc" Oct 25 09:24:14 volumio go-librespot[3719]: time="2024-10-25T09:24:14+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:14 volumio go-librespot[3719]: time="2024-10-25T09:24:14+03:00" 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" Oct 25 09:24:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:15 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:15 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 203. Oct 25 09:24:17 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:17 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:17 volumio go-librespot[3726]: Librespot-go daemon starting... Oct 25 09:24:17 volumio go-librespot[3726]: time="2024-10-25T09:24:17+03:00" level=info msg="generated new device id: d647404ef1bfd313c896674f7a3ea5173ec8d6a9" Oct 25 09:24:17 volumio go-librespot[3726]: time="2024-10-25T09:24:17+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:17 volumio go-librespot[3726]: time="2024-10-25T09:24:17+03:00" 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" Oct 25 09:24:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:18 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:18 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 204. Oct 25 09:24:20 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:20 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:20 volumio go-librespot[3733]: Librespot-go daemon starting... Oct 25 09:24:20 volumio go-librespot[3733]: time="2024-10-25T09:24:20+03:00" level=info msg="generated new device id: 74d8dd038e0431f9d87383e347451d31cbcaa559" Oct 25 09:24:20 volumio go-librespot[3733]: time="2024-10-25T09:24:20+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:20 volumio go-librespot[3733]: time="2024-10-25T09:24:20+03:00" 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" Oct 25 09:24:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:21 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:21 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 205. Oct 25 09:24:23 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:24 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:24 volumio go-librespot[3740]: Librespot-go daemon starting... Oct 25 09:24:24 volumio go-librespot[3740]: time="2024-10-25T09:24:24+03:00" level=info msg="generated new device id: 723e62ee0ac9d1ae02eb5384ebffa086a1f94fff" Oct 25 09:24:24 volumio go-librespot[3740]: time="2024-10-25T09:24:24+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:24 volumio go-librespot[3740]: time="2024-10-25T09:24:24+03:00" 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" Oct 25 09:24:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:24 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:24 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 206. Oct 25 09:24:27 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:27 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:27 volumio go-librespot[3747]: Librespot-go daemon starting... Oct 25 09:24:27 volumio go-librespot[3747]: time="2024-10-25T09:24:27+03:00" level=info msg="generated new device id: b59238aa2ff525f061097f431ceaa61c2fd6fee3" Oct 25 09:24:27 volumio go-librespot[3747]: time="2024-10-25T09:24:27+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:27 volumio go-librespot[3747]: time="2024-10-25T09:24:27+03:00" 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" Oct 25 09:24:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:27 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:27 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 207. Oct 25 09:24:30 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:30 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:30 volumio go-librespot[3754]: Librespot-go daemon starting... Oct 25 09:24:30 volumio go-librespot[3754]: time="2024-10-25T09:24:30+03:00" level=info msg="generated new device id: 937aa959d85738ec8078c60f77aea86a1572164e" Oct 25 09:24:30 volumio go-librespot[3754]: time="2024-10-25T09:24:30+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:30 volumio go-librespot[3754]: time="2024-10-25T09:24:30+03:00" 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" Oct 25 09:24:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:30 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:30 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 208. Oct 25 09:24:33 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:33 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:33 volumio go-librespot[3761]: Librespot-go daemon starting... Oct 25 09:24:33 volumio go-librespot[3761]: time="2024-10-25T09:24:33+03:00" level=info msg="generated new device id: 9b94f68ea4589477aca94a8944da37fc6477a088" Oct 25 09:24:33 volumio go-librespot[3761]: time="2024-10-25T09:24:33+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:33 volumio go-librespot[3761]: time="2024-10-25T09:24:33+03:00" 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" Oct 25 09:24:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:33 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:33 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:36 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:36 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 209. Oct 25 09:24:36 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:36 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:36 volumio go-librespot[3768]: Librespot-go daemon starting... Oct 25 09:24:37 volumio go-librespot[3768]: time="2024-10-25T09:24:37+03:00" level=info msg="generated new device id: 34702cc421c40d9724ff88039bf77ea43abbe7aa" Oct 25 09:24:37 volumio go-librespot[3768]: time="2024-10-25T09:24:37+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:37 volumio go-librespot[3768]: time="2024-10-25T09:24:37+03:00" 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" Oct 25 09:24:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:39 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:39 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 210. Oct 25 09:24:40 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:40 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:40 volumio go-librespot[3775]: Librespot-go daemon starting... Oct 25 09:24:40 volumio go-librespot[3775]: time="2024-10-25T09:24:40+03:00" level=info msg="generated new device id: ae1b50a4f3e431e943f4db7ac0861d56cf4d0a0c" Oct 25 09:24:40 volumio go-librespot[3775]: time="2024-10-25T09:24:40+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:40 volumio go-librespot[3775]: time="2024-10-25T09:24:40+03:00" 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" Oct 25 09:24:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:42 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:42 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 211. Oct 25 09:24:43 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:43 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:43 volumio go-librespot[3782]: Librespot-go daemon starting... Oct 25 09:24:43 volumio go-librespot[3782]: time="2024-10-25T09:24:43+03:00" level=info msg="generated new device id: b308125eec5cc02fc49290a1a9fea9dabbc87ad7" Oct 25 09:24:43 volumio go-librespot[3782]: time="2024-10-25T09:24:43+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:43 volumio go-librespot[3782]: time="2024-10-25T09:24:43+03:00" 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" Oct 25 09:24:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:45 volumio ntpd[924]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Oct 25 09:24:45 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:45 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 212. Oct 25 09:24:46 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:46 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:46 volumio go-librespot[3789]: Librespot-go daemon starting... Oct 25 09:24:46 volumio go-librespot[3789]: time="2024-10-25T09:24:46+03:00" level=info msg="generated new device id: f5b3600363b886aa1d24769b897963de4af36600" Oct 25 09:24:46 volumio go-librespot[3789]: time="2024-10-25T09:24:46+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:46 volumio go-librespot[3789]: time="2024-10-25T09:24:46+03:00" 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" Oct 25 09:24:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:47 volumio ntpd[924]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Oct 25 09:24:48 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:48 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:49 volumio ntpd[924]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Oct 25 09:24:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 213. Oct 25 09:24:49 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:50 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:50 volumio go-librespot[3841]: Librespot-go daemon starting... Oct 25 09:24:50 volumio go-librespot[3841]: time="2024-10-25T09:24:50+03:00" level=info msg="generated new device id: 26606ec3947f90596917cdd408d7b1a7cdc5a16a" Oct 25 09:24:50 volumio go-librespot[3841]: time="2024-10-25T09:24:50+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:50 volumio go-librespot[3841]: time="2024-10-25T09:24:50+03:00" 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" Oct 25 09:24:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:51 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:51 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 214. Oct 25 09:24:53 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:53 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:53 volumio go-librespot[3848]: Librespot-go daemon starting... Oct 25 09:24:53 volumio go-librespot[3848]: time="2024-10-25T09:24:53+03:00" level=info msg="generated new device id: b7d94bdd015598113e57b8ab1f573f674feb829e" Oct 25 09:24:53 volumio go-librespot[3848]: time="2024-10-25T09:24:53+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:53 volumio go-librespot[3848]: time="2024-10-25T09:24:53+03:00" 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" Oct 25 09:24:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:53 volumio ntpd[924]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Oct 25 09:24:54 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:54 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 215. Oct 25 09:24:56 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:56 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:56 volumio go-librespot[3855]: Librespot-go daemon starting... Oct 25 09:24:56 volumio go-librespot[3855]: time="2024-10-25T09:24:56+03:00" level=info msg="generated new device id: edc0b03a2d141fee4ce374c6e16259c0c3c0a972" Oct 25 09:24:56 volumio go-librespot[3855]: time="2024-10-25T09:24:56+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:56 volumio go-librespot[3855]: time="2024-10-25T09:24:56+03:00" 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" Oct 25 09:24:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:24:57 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:24:57 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:24:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:24:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 216. Oct 25 09:24:59 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:24:59 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:24:59 volumio go-librespot[3862]: Librespot-go daemon starting... Oct 25 09:24:59 volumio go-librespot[3862]: time="2024-10-25T09:24:59+03:00" level=info msg="generated new device id: 7f66341e3315c8f093c73507414c15ab7c74a635" Oct 25 09:24:59 volumio go-librespot[3862]: time="2024-10-25T09:24:59+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:24:59 volumio go-librespot[3862]: time="2024-10-25T09:24:59+03:00" 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" Oct 25 09:24:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:24:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:00 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:00 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 217. Oct 25 09:25:02 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:03 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:03 volumio go-librespot[3869]: Librespot-go daemon starting... Oct 25 09:25:03 volumio go-librespot[3869]: time="2024-10-25T09:25:03+03:00" level=info msg="generated new device id: d67f26908e16e010f774eccd3ddd855716202f38" Oct 25 09:25:03 volumio go-librespot[3869]: time="2024-10-25T09:25:03+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:03 volumio go-librespot[3869]: time="2024-10-25T09:25:03+03:00" 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" Oct 25 09:25:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:03 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:03 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 218. Oct 25 09:25:06 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:06 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:06 volumio go-librespot[3876]: Librespot-go daemon starting... Oct 25 09:25:06 volumio go-librespot[3876]: time="2024-10-25T09:25:06+03:00" level=info msg="generated new device id: ee020974cd1937a0ab77599cd2d3e8a152621d26" Oct 25 09:25:06 volumio go-librespot[3876]: time="2024-10-25T09:25:06+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:06 volumio go-librespot[3876]: time="2024-10-25T09:25:06+03:00" 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" Oct 25 09:25:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:06 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:06 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 219. Oct 25 09:25:09 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:09 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:09 volumio go-librespot[3883]: Librespot-go daemon starting... Oct 25 09:25:09 volumio go-librespot[3883]: time="2024-10-25T09:25:09+03:00" level=info msg="generated new device id: 268380c3f2c41dcc17de63ab5e87dc0c8613a069" Oct 25 09:25:09 volumio go-librespot[3883]: time="2024-10-25T09:25:09+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:09 volumio go-librespot[3883]: time="2024-10-25T09:25:09+03:00" 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" Oct 25 09:25:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:09 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:09 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 220. Oct 25 09:25:12 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:12 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:12 volumio go-librespot[3890]: Librespot-go daemon starting... Oct 25 09:25:12 volumio go-librespot[3890]: time="2024-10-25T09:25:12+03:00" level=info msg="generated new device id: c7802fd8cb1fb4566637b561b755bff139bbb8a6" Oct 25 09:25:12 volumio go-librespot[3890]: time="2024-10-25T09:25:12+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:12 volumio go-librespot[3890]: time="2024-10-25T09:25:12+03:00" 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" Oct 25 09:25:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:12 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:12 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221. Oct 25 09:25:15 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:15 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:15 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:15 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:15 volumio go-librespot[3897]: Librespot-go daemon starting... Oct 25 09:25:16 volumio go-librespot[3897]: time="2024-10-25T09:25:16+03:00" level=info msg="generated new device id: bf79f78dc989e3564ac782f1c710c5e5dc25440c" Oct 25 09:25:16 volumio go-librespot[3897]: time="2024-10-25T09:25:16+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:16 volumio go-librespot[3897]: time="2024-10-25T09:25:16+03:00" 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" Oct 25 09:25:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:18 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:18 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222. Oct 25 09:25:19 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:19 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:19 volumio go-librespot[3904]: Librespot-go daemon starting... Oct 25 09:25:19 volumio go-librespot[3904]: time="2024-10-25T09:25:19+03:00" level=info msg="generated new device id: ac27800f96803ec071a4d8089dd18c570f513e9e" Oct 25 09:25:19 volumio go-librespot[3904]: time="2024-10-25T09:25:19+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:19 volumio go-librespot[3904]: time="2024-10-25T09:25:19+03:00" 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" Oct 25 09:25:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:21 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:22 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223. Oct 25 09:25:22 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:22 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:22 volumio go-librespot[3911]: Librespot-go daemon starting... Oct 25 09:25:22 volumio go-librespot[3911]: time="2024-10-25T09:25:22+03:00" level=info msg="generated new device id: 8c39cb7cfd2bf5a42a1d2ecf654e0c6df579b463" Oct 25 09:25:22 volumio go-librespot[3911]: time="2024-10-25T09:25:22+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:22 volumio go-librespot[3911]: time="2024-10-25T09:25:22+03:00" 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" Oct 25 09:25:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:25 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:25 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 224. Oct 25 09:25:25 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:25 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:25 volumio go-librespot[3918]: Librespot-go daemon starting... Oct 25 09:25:25 volumio go-librespot[3918]: time="2024-10-25T09:25:25+03:00" level=info msg="generated new device id: 1907d8fac9eb7572cf85740a67bf2b1c8a8c2a32" Oct 25 09:25:25 volumio go-librespot[3918]: time="2024-10-25T09:25:25+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:25 volumio go-librespot[3918]: time="2024-10-25T09:25:25+03:00" 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" Oct 25 09:25:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:28 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:28 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 225. Oct 25 09:25:28 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:29 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:29 volumio go-librespot[3925]: Librespot-go daemon starting... Oct 25 09:25:29 volumio go-librespot[3925]: time="2024-10-25T09:25:29+03:00" level=info msg="generated new device id: ef370d074dab530ab290a57e4644c6f0c2d67fb1" Oct 25 09:25:29 volumio go-librespot[3925]: time="2024-10-25T09:25:29+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:29 volumio go-librespot[3925]: time="2024-10-25T09:25:29+03:00" 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" Oct 25 09:25:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:29 volumio wpa_supplicant[1075]: wlan0: SME: Trying to authenticate with 66:c2:de:8a:c6:4a (SSID='V30+_ismail' freq=2412 MHz) Oct 25 09:25:29 volumio kernel: wlan0: authenticate with 66:c2:de:8a:c6:4a Oct 25 09:25:29 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Oct 25 09:25:29 volumio wpa_supplicant[1075]: wlan0: Trying to associate with 66:c2:de:8a:c6:4a (SSID='V30+_ismail' freq=2412 MHz) Oct 25 09:25:29 volumio kernel: wlan0: send auth to 66:c2:de:8a:c6:4a (try 1/3) Oct 25 09:25:29 volumio kernel: wlan0: authenticated Oct 25 09:25:29 volumio kernel: wlan0: associate with 66:c2:de:8a:c6:4a (try 1/3) Oct 25 09:25:29 volumio wpa_supplicant[1075]: wlan0: Associated with 66:c2:de:8a:c6:4a Oct 25 09:25:29 volumio kernel: wlan0: RX AssocResp from 66:c2:de:8a:c6:4a (capab=0x1431 status=0 aid=2) Oct 25 09:25:29 volumio kernel: wlan0: associated Oct 25 09:25:29 volumio wpa_supplicant[1075]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 25 09:25:29 volumio wpa_supplicant[1075]: wlan0: WPA: Key negotiation completed with 66:c2:de:8a:c6:4a [PTK=CCMP GTK=CCMP] Oct 25 09:25:29 volumio wpa_supplicant[1075]: wlan0: CTRL-EVENT-CONNECTED - Connection to 66:c2:de:8a:c6:4a completed [id=0 id_str=] Oct 25 09:25:29 volumio dhcpcd[830]: wlan0: carrier acquired Oct 25 09:25:29 volumio dhcpcd[830]: DUID 00:04:76:a6:70:56:e9:82:e2:11:9e:12:d0:e7:82:05:0a:36 Oct 25 09:25:29 volumio dhcpcd[830]: wlan0: IAID 5a:62:5b:71 Oct 25 09:25:29 volumio dhcpcd[830]: wlan0: adding address fe80::7dfb:74d0:5df7:311f Oct 25 09:25:29 volumio dhcpcd[830]: ipv6_addaddr1: Permission denied Oct 25 09:25:30 volumio dhcpcd[830]: wlan0: soliciting a DHCP lease Oct 25 09:25:30 volumio dhcpcd[830]: wlan0: soliciting an IPv6 router Oct 25 09:25:31 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:31 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 226. Oct 25 09:25:32 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:32 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:32 volumio go-librespot[3948]: Librespot-go daemon starting... Oct 25 09:25:32 volumio go-librespot[3948]: time="2024-10-25T09:25:32+03:00" level=info msg="generated new device id: 765f9fa4b1e41a3ba473df16faf17187b6a5246e" Oct 25 09:25:32 volumio go-librespot[3948]: time="2024-10-25T09:25:32+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:32 volumio go-librespot[3948]: time="2024-10-25T09:25:32+03:00" 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" Oct 25 09:25:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:33 volumio dhcpcd[830]: wlan0: offered 192.168.43.25 from 192.168.43.1 Oct 25 09:25:33 volumio dhcpcd[830]: wlan0: probing address 192.168.43.25/24 Oct 25 09:25:34 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:34 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 227. Oct 25 09:25:35 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:35 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:35 volumio go-librespot[3955]: Librespot-go daemon starting... Oct 25 09:25:35 volumio go-librespot[3955]: time="2024-10-25T09:25:35+03:00" level=info msg="generated new device id: f18a9b061a4f2bce51fe6214b183636fe8b8d151" Oct 25 09:25:35 volumio go-librespot[3955]: time="2024-10-25T09:25:35+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:35 volumio go-librespot[3955]: time="2024-10-25T09:25:35+03:00" 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" Oct 25 09:25:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:37 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:37 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:38 volumio dhcpcd[830]: wlan0: leased 192.168.43.25 for 7200 seconds Oct 25 09:25:38 volumio dhcpcd[830]: wlan0: adding route to 192.168.43.0/24 Oct 25 09:25:38 volumio dhcpcd[830]: wlan0: adding default route via 192.168.43.1 Oct 25 09:25:38 volumio avahi-daemon[774]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.43.25. Oct 25 09:25:38 volumio avahi-daemon[774]: New relevant interface wlan0.IPv4 for mDNS. Oct 25 09:25:38 volumio avahi-daemon[774]: Registering new address record for 192.168.43.25 on wlan0.IPv4. Oct 25 09:25:38 volumio ntpd[924]: ntpd exiting on signal 15 (Terminated) Oct 25 09:25:38 volumio systemd[1]: Stopping Network Time Service... Oct 25 09:25:38 volumio systemd[1]: ntp.service: Succeeded. Oct 25 09:25:38 volumio systemd[1]: Stopped Network Time Service. Oct 25 09:25:38 volumio systemd[1]: Starting Network Time Service... Oct 25 09:25:38 volumio ntpd[3995]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 25 09:25:38 volumio ntpd[3995]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 25 09:25:38 volumio systemd[1]: Started Network Time Service. Oct 25 09:25:38 volumio ntpd[4001]: proto: precision = 0.114 usec (-23) Oct 25 09:25:38 volumio ntpd[4001]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 25 09:25:38 volumio ntpd[4001]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 25 09:25:38 volumio ntpd[4001]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 668 days ago Oct 25 09:25:38 volumio ntpd[4001]: Listen and drop on 0 v6wildcard [::]:123 Oct 25 09:25:38 volumio ntpd[4001]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 25 09:25:38 volumio ntpd[4001]: Listen normally on 2 lo 127.0.0.1:123 Oct 25 09:25:38 volumio ntpd[4001]: Listen normally on 3 wlan0 192.168.43.25:123 Oct 25 09:25:38 volumio ntpd[4001]: Listening on routing socket on fd #20 for interface updates Oct 25 09:25:38 volumio ntpd[4001]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 25 09:25:38 volumio ntpd[4001]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 25 09:25:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 228. Oct 25 09:25:38 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:38 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:38 volumio go-librespot[4004]: Librespot-go daemon starting... Oct 25 09:25:38 volumio go-librespot[4004]: time="2024-10-25T09:25:38+03:00" level=info msg="generated new device id: 41f7083a87c13ee91ef328cbcf997668c5ae24d7" Oct 25 09:25:38 volumio go-librespot[4004]: time="2024-10-25T09:25:38+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:39 volumio go-librespot[4004]: time="2024-10-25T09:25:39+03: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 25 09:25:39 volumio go-librespot[4004]: time="2024-10-25T09:25:39+03: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 25 09:25:39 volumio go-librespot[4004]: time="2024-10-25T09:25:39+03: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 25 09:25:39 volumio go-librespot[4004]: time="2024-10-25T09:25:39+03:00" level=debug msg="zeroconf server listening on port 40535" Oct 25 09:25:39 volumio volumio[1139]: info: Discovery: adding 9b02629d-80b1-4dc9-974d-80698d81e4cd Oct 25 09:25:39 volumio volumio[1139]: info: Discovery: Found device Volumio Oct 25 09:25:39 volumio volumio[1139]: info: CoreCommandRouter::volumioGetState Oct 25 09:25:39 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Oct 25 09:25:39 volumio go-librespot[4004]: time="2024-10-25T09:25:39+03:00" level=debug msg="obtained new client token: AACRx77GxvypHV6DyuvdDJQUlZO6DMTFIneoL6HkbUPVvBksJq5sRh7NWOkAfZ3zPKjx/tyd0pfplqRQE+jT3DXt+yUSE23KvEUfoprHdDWkdfcdN3MTvy0buwMfHxpKfhEPqvCZWqO3Xkl0V1lKCRktO24g1Sptjf5x1o7Ox0fp0DAHLDR/ZACxT1+frubXJsh8JK34jl0aHnc+0tNNCHg9KedZiht3D9wP14tt4EfZD6Cd7u7ScYZJ2DUBHQ==" Oct 25 09:25:39 volumio ntpd[4001]: Soliciting pool server 101.44.222.53 Oct 25 09:25:39 volumio go-librespot[4004]: time="2024-10-25T09:25:39+03:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Oct 25 09:25:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 25 09:25:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 25 09:25:40 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:40 volumio volumio[1139]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 09:25:40 volumio ntpd[4001]: Soliciting pool server 161.9.147.35 Oct 25 09:25:40 volumio ntpd[4001]: Soliciting pool server 45.136.155.37 Oct 25 09:25:41 volumio ntpd[4001]: Soliciting pool server 85.199.214.98 Oct 25 09:25:41 volumio ntpd[4001]: Soliciting pool server 212.154.83.90 Oct 25 09:25:41 volumio ntpd[4001]: Soliciting pool server 62.12.173.12 Oct 25 09:25:42 volumio ntpd[4001]: Soliciting pool server 37.187.145.181 Oct 25 09:25:42 volumio ntpd[4001]: Soliciting pool server 176.235.250.150 Oct 25 09:25:42 volumio ntpd[4001]: Soliciting pool server 194.27.156.207 Oct 25 09:25:42 volumio ntpd[4001]: Soliciting pool server 178.79.155.116 Oct 25 09:25:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 25 09:25:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 229. Oct 25 09:25:42 volumio systemd[1]: Stopped go-librespot Daemon. Oct 25 09:25:42 volumio systemd[1]: Started go-librespot Daemon. Oct 25 09:25:42 volumio go-librespot[4013]: Librespot-go daemon starting... Oct 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03:00" level=info msg="generated new device id: 613c36fc9de8c509d03620e3d9f5026cc049ea6d" Oct 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03:00" level=debug msg="stored credentials found for 11128712632" Oct 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03: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 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03: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 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03: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 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03:00" level=debug msg="zeroconf server listening on port 36817" Oct 25 09:25:42 volumio go-librespot[4013]: time="2024-10-25T09:25:42+03:00" level=debug msg="obtained new client token: AAB6ceFgK1IgWqyqC22V7extaHl+ahbgveCYwGBJUBE2s+P4JXR2kAfcUjVFLPD55H2h/xUw1eusG9e2uBJyRQtYhHmqKx/2zsYEZZ11W5rt6hjqwhDlIojWTMwslmCCzs+0zPHiGJ9X9FAnRtDREsBDJe3xj4G+8fwajc8mf72ZckkVobrpPOii9tbHT3T1DDxAJdqaQXd8PtGLx0pMthfE7ciLNC966Xj8AJ2ymfhF5RF75QWOFgTkiA994g==" Oct 25 09:25:43 volumio volumio[1139]: info: Initializing connection to go-librespot Websocket Oct 25 09:25:43 volumio go-librespot[4013]: time="2024-10-25T09:25:43+03:00" level=debug msg="new websocket client" Oct 25 09:25:43 volumio volumio[1139]: info: Connection to go-librespot Websocket established Oct 25 09:25:43 volumio go-librespot[4013]: time="2024-10-25T09:25:43+03:00" level=debug msg="completed keyexchange" Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 25 09:25:43 volumio volumio[1139]: info: Adding plugin bluetooth to MyMusic Plugins Oct 25 09:25:43 volumio volumio[1139]: info: Adding plugin multiroom to MyMusic Plugins Oct 25 09:25:43 volumio volumio[1139]: info: Adding plugin metavolumio to MyMusic Plugins Oct 25 09:25:43 volumio volumio[1139]: info: Adding plugin cd_controller to MyMusic Plugins Oct 25 09:25:43 volumio volumio[1139]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 25 09:25:43 volumio volumio[1139]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 25 09:25:43 volumio ntpd[4001]: Soliciting pool server 93.115.79.15 Oct 25 09:25:43 volumio ntpd[4001]: Soliciting pool server 2a0d:5642:140:9:5054:ff:fec4:f01 Oct 25 09:25:43 volumio ntpd[4001]: Soliciting pool server 162.159.200.1 Oct 25 09:25:43 volumio ntpd[4001]: Soliciting pool server 194.27.222.5 Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 25 09:25:43 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 09:25:43 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 09:25:43 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 09:25:43 volumio volumio[1139]: info: Starting MyVolumio Remote Streaming Endpoints Oct 25 09:25:43 volumio volumio[1139]: info: MyVolumio login type: Token Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 25 09:25:43 volumio go-librespot[4013]: time="2024-10-25T09:25:43+03:00" level=debug msg="completed challenge" Oct 25 09:25:43 volumio go-librespot[4013]: time="2024-10-25T09:25:43+03:00" level=debug msg="authenticated as 11128712632" Oct 25 09:25:43 volumio volumio[1139]: info: Starting Streaming Service Transparent Proxy Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 25 09:25:43 volumio volumio[1139]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 25 09:25:43 volumio volumio[1139]: info: Streaming services startup Oct 25 09:25:43 volumio volumio[1139]: info: Starting Streaming Daemon Oct 25 09:25:44 volumio sudo[4028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 25 09:25:44 volumio sudo[4028]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 09:25:44 volumio sudo[4028]: pam_unix(sudo:session): session closed for user root Oct 25 09:25:44 volumio volumio[1139]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 25 09:25:44 volumio volumio[1139]: error: Cannot start Volumio Streaming Daemon Oct 25 09:25:44 volumio volumio[1139]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 25 09:25:44 volumio volumio[1139]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="authenticated as 11128712632" Oct 25 09:25:44 volumio volumio[1139]: STREAMING PROXY: Starting server on port 3245 Oct 25 09:25:44 volumio volumio[1139]: Node JS runtime: 14 Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="dealer connection opened" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="initializing zeroconf session, username: 11128712632" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="autoplay enabled: false" Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="received connection id: ZTgxODNkNDEtMTFhZi00NDE2LTliMGItY2ExYmQzZTQ5YjdhK2RlYWxlcit0Y3A6Ly8wYWNhNTkxYy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArODdCODQyNzBBQ0RFRDRCM0Q3NzQ3Mjk1RUY0NjBERDAyOEFFMTBFMkU2Mzg5NTI1RjRGQjVBNEExN0NEQTVFOQ==" Oct 25 09:25:44 volumio ntpd[4001]: Soliciting pool server 62.12.173.11 Oct 25 09:25:44 volumio volumio[1139]: error: MyVolumio Custom Token format not valid, refreshing it Oct 25 09:25:44 volumio ntpd[4001]: Soliciting pool server 89.252.135.27 Oct 25 09:25:44 volumio go-librespot[4013]: time="2024-10-25T09:25:44+03:00" level=debug msg="put connect state because NEW_DEVICE" Oct 25 09:25:45 volumio ntpd[4001]: Soliciting pool server 192.36.143.130 Oct 25 09:25:45 volumio volumio[1139]: info: MyVolumio login type: Token Oct 25 09:25:46 volumio volumio[1139]: info: Getting Spotify volume Oct 25 09:25:46 volumio volumio[1139]: info: Spotify volume: 100 Oct 25 09:25:46 volumio volumio[1139]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 25 09:25:46 volumio volumio[1139]: info: CoreCommandRouter::volumioGetState Oct 25 09:25:46 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Oct 25 09:25:46 volumio volumio[1139]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37 Oct 25 09:25:46 volumio volumio[1139]: SPOTIFY: SPOTIFY VOLUME 100 Oct 25 09:25:46 volumio volumio[1139]: SPOTIFY: VOLUMIO VOLUME 37 Oct 25 09:25:46 volumio volumio[1139]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 25 09:25:46 volumio volumio[1139]: info: Setting Spotify Volume from Volumio: 37 Oct 25 09:25:46 volumio volumio[1139]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 25 09:25:46 volumio ntpd[4001]: Soliciting pool server 162.159.200.123 Oct 25 09:25:47 volumio volumio[1139]: info: MyVolumio token set successfully Oct 25 09:25:47 volumio volumio[1139]: info: MYVOLUMIO: Adding device Oct 25 09:25:47 volumio volumio[1139]: info: MYVOLUMIO: Evaluating Server Oct 25 09:25:47 volumio volumio[1139]: info: MyVolumio status changed Oct 25 09:25:47 volumio volumio[1139]: info: Streaming services startup Oct 25 09:25:47 volumio volumio[1139]: info: Starting Streaming Daemon Oct 25 09:25:47 volumio volumio[1139]: info: Removing browser output: myVolumio user plan is not superstar Oct 25 09:25:47 volumio volumio[1139]: info: Removing audio output: Oct 25 09:25:47 volumio volumio[1139]: info: Stoppping Tunnel 1 Oct 25 09:25:47 volumio sudo[4053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 25 09:25:47 volumio sudo[4053]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 09:25:47 volumio sudo[4053]: pam_unix(sudo:session): session closed for user root Oct 25 09:25:47 volumio volumio[1139]: error: Cannot start Volumio Streaming Daemon Oct 25 09:25:47 volumio volumio[1139]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 25 09:25:47 volumio volumio[1139]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 25 09:25:47 volumio sudo[4056]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 25 09:25:47 volumio sudo[4056]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 09:25:47 volumio sudo[4056]: pam_unix(sudo:session): session closed for user root Oct 25 09:25:47 volumio volumio[1139]: info: Remote SSH Stopped Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.61a82007 does not match aorg 0000000000.00000000 from server@161.9.147.35 xmt 0xeac5b86b.12fbe9bf Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.61a68497 does not match aorg 0000000000.00000000 from server@194.27.156.207 xmt 0xeac5b86b.14501229 Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.61a5f661 does not match aorg 0000000000.00000000 from server@37.187.145.181 xmt 0xeac5b86b.16106a8f Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.61a1165f does not match aorg 0000000000.00000000 from server@62.12.173.11 xmt 0xeac5b86b.1563e5d3 Oct 25 09:25:47 volumio volumio[1139]: error: Failed to ping endpoint eu5.myvolumio.org : unknown error Oct 25 09:25:47 volumio volumio[1139]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.61a714ca does not match aorg 0000000000.00000000 from server@85.199.214.98 xmt 0xeac5b86b.189a3c6d Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.61a538bc does not match aorg 0000000000.00000000 from server@178.79.155.116 xmt 0xeac5b86b.1686ca2e Oct 25 09:25:47 volumio volumio[1139]: Error: Unable to resolve or reject the same promise twice Oct 25 09:25:47 volumio volumio[1139]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 25 09:25:47 volumio volumio[1139]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Oct 25 09:25:47 volumio volumio[1139]: at Socket.emit (events.js:412:35) Oct 25 09:25:47 volumio volumio[1139]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 25 09:25:47 volumio volumio[1139]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 25 09:25:47 volumio volumio[1139]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 09:25:47 volumio ntpd[4001]: receive: Unexpected origin timestamp 0xeac5b86b.619d0628 does not match aorg 0000000000.00000000 from server@192.36.143.130 xmt 0xeac5b86b.15ec0863 Oct 25 09:25:47 volumio sudo[4068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 09:24 Oct 25 09:25:47 volumio sudo[4068]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"