-- Logs begin at Sat 2025-05-17 02:55:43 UTC, end at Sat 2025-05-17 03:00:25 UTC. -- May 17 02:59:00 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:00 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:00 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. May 17 02:59:01 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:01 volumio go-librespot[1974]: go-librespot daemon starting... May 17 02:59:01 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:01 volumio go-librespot[1974]: time="2025-05-17T02:59:01Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:01 volumio go-librespot[1974]: time="2025-05-17T02:59:01Z" level=debug msg="app state loaded" May 17 02:59:01 volumio go-librespot[1974]: time="2025-05-17T02:59:01Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:01 volumio go-librespot[1974]: time="2025-05-17T02:59:01Z" 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" May 17 02:59:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:01 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:01 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:02 volumio ntpd[790]: error resolving pool 1.debian.pool.ntp.org: System error (-11) May 17 02:59:03 volumio ntpd[790]: error resolving pool 0.debian.pool.ntp.org: System error (-11) May 17 02:59:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. May 17 02:59:04 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:04 volumio go-librespot[1979]: go-librespot daemon starting... May 17 02:59:04 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:04 volumio go-librespot[1979]: time="2025-05-17T02:59:04Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:04 volumio go-librespot[1979]: time="2025-05-17T02:59:04Z" level=debug msg="app state loaded" May 17 02:59:04 volumio go-librespot[1979]: time="2025-05-17T02:59:04Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:04 volumio go-librespot[1979]: time="2025-05-17T02:59: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" May 17 02:59:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:04 volumio ntpd[790]: error resolving pool 2.debian.pool.ntp.org: System error (-11) May 17 02:59:04 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:04 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:05 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:05 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:05 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:05 volumio ntpd[790]: error resolving pool 3.debian.pool.ntp.org: System error (-11) May 17 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. May 17 02:59:07 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:07 volumio go-librespot[1992]: go-librespot daemon starting... May 17 02:59:07 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:07 volumio go-librespot[1992]: time="2025-05-17T02:59:07Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:07 volumio go-librespot[1992]: time="2025-05-17T02:59:07Z" level=debug msg="app state loaded" May 17 02:59:07 volumio go-librespot[1992]: time="2025-05-17T02:59:07Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:07 volumio go-librespot[1992]: time="2025-05-17T02:59: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" May 17 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:07 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:07 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:10 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:10 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:10 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:10 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:10 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. May 17 02:59:10 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:10 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:10 volumio go-librespot[2016]: go-librespot daemon starting... May 17 02:59:10 volumio go-librespot[2016]: time="2025-05-17T02:59:10Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:10 volumio go-librespot[2016]: time="2025-05-17T02:59:10Z" level=debug msg="app state loaded" May 17 02:59:10 volumio go-librespot[2016]: time="2025-05-17T02:59:10Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:10 volumio go-librespot[2016]: time="2025-05-17T02:59: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" May 17 02:59:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:13 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:13 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. May 17 02:59:14 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:14 volumio go-librespot[2021]: go-librespot daemon starting... May 17 02:59:14 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:14 volumio go-librespot[2021]: time="2025-05-17T02:59:14Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:14 volumio go-librespot[2021]: time="2025-05-17T02:59:14Z" level=debug msg="app state loaded" May 17 02:59:14 volumio go-librespot[2021]: time="2025-05-17T02:59:14Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:14 volumio go-librespot[2021]: time="2025-05-17T02:59:14Z" 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" May 17 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:15 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:15 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:15 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:16 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:16 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. May 17 02:59:17 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:17 volumio go-librespot[2031]: go-librespot daemon starting... May 17 02:59:17 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:17 volumio go-librespot[2031]: time="2025-05-17T02:59:17Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:17 volumio go-librespot[2031]: time="2025-05-17T02:59:17Z" level=debug msg="app state loaded" May 17 02:59:17 volumio go-librespot[2031]: time="2025-05-17T02:59:17Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:17 volumio go-librespot[2031]: time="2025-05-17T02:59: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" May 17 02:59:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:19 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:19 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:20 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:20 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:20 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. May 17 02:59:20 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:20 volumio go-librespot[2055]: go-librespot daemon starting... May 17 02:59:20 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:20 volumio go-librespot[2055]: time="2025-05-17T02:59:20Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:20 volumio go-librespot[2055]: time="2025-05-17T02:59:20Z" level=debug msg="app state loaded" May 17 02:59:20 volumio go-librespot[2055]: time="2025-05-17T02:59:20Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:20 volumio go-librespot[2055]: time="2025-05-17T02:59: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" May 17 02:59:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:22 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:22 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. May 17 02:59:23 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:23 volumio go-librespot[2060]: go-librespot daemon starting... May 17 02:59:23 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:23 volumio go-librespot[2060]: time="2025-05-17T02:59:23Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:23 volumio go-librespot[2060]: time="2025-05-17T02:59:23Z" level=debug msg="app state loaded" May 17 02:59:23 volumio go-librespot[2060]: time="2025-05-17T02:59:23Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:23 volumio go-librespot[2060]: time="2025-05-17T02:59: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" May 17 02:59:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:25 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:25 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:25 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:25 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:25 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. May 17 02:59:27 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:27 volumio go-librespot[2073]: go-librespot daemon starting... May 17 02:59:27 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:27 volumio go-librespot[2073]: time="2025-05-17T02:59:27Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:27 volumio go-librespot[2073]: time="2025-05-17T02:59:27Z" level=debug msg="app state loaded" May 17 02:59:27 volumio go-librespot[2073]: time="2025-05-17T02:59:27Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:27 volumio go-librespot[2073]: time="2025-05-17T02:59:27Z" 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" May 17 02:59:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:28 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:28 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. May 17 02:59:30 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:30 volumio go-librespot[2092]: go-librespot daemon starting... May 17 02:59:30 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:30 volumio go-librespot[2092]: time="2025-05-17T02:59:30Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:30 volumio go-librespot[2092]: time="2025-05-17T02:59:30Z" level=debug msg="app state loaded" May 17 02:59:30 volumio go-librespot[2092]: time="2025-05-17T02:59:30Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:30 volumio go-librespot[2092]: time="2025-05-17T02:59: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" May 17 02:59:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:30 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:30 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:30 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:31 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:31 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. May 17 02:59:33 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:33 volumio go-librespot[2102]: go-librespot daemon starting... May 17 02:59:33 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:33 volumio go-librespot[2102]: time="2025-05-17T02:59:33Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:33 volumio go-librespot[2102]: time="2025-05-17T02:59:33Z" level=debug msg="app state loaded" May 17 02:59:33 volumio go-librespot[2102]: time="2025-05-17T02:59:33Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:33 volumio go-librespot[2102]: time="2025-05-17T02:59: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" May 17 02:59:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:34 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:34 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:35 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:35 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:35 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. May 17 02:59:36 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:36 volumio go-librespot[2112]: go-librespot daemon starting... May 17 02:59:36 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:36 volumio go-librespot[2112]: time="2025-05-17T02:59:36Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:36 volumio go-librespot[2112]: time="2025-05-17T02:59:36Z" level=debug msg="app state loaded" May 17 02:59:36 volumio go-librespot[2112]: time="2025-05-17T02:59:36Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:36 volumio go-librespot[2112]: time="2025-05-17T02:59: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" May 17 02:59:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:37 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:37 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. May 17 02:59:40 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:40 volumio go-librespot[2131]: go-librespot daemon starting... May 17 02:59:40 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:40 volumio go-librespot[2131]: time="2025-05-17T02:59:40Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:40 volumio go-librespot[2131]: time="2025-05-17T02:59:40Z" level=debug msg="app state loaded" May 17 02:59:40 volumio go-librespot[2131]: time="2025-05-17T02:59:40Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:40 volumio go-librespot[2131]: time="2025-05-17T02:59:40Z" 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" May 17 02:59:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:40 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:40 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:40 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:40 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:40 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. May 17 02:59:43 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:43 volumio go-librespot[2141]: go-librespot daemon starting... May 17 02:59:43 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:43 volumio go-librespot[2141]: time="2025-05-17T02:59:43Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:43 volumio go-librespot[2141]: time="2025-05-17T02:59:43Z" level=debug msg="app state loaded" May 17 02:59:43 volumio go-librespot[2141]: time="2025-05-17T02:59:43Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:43 volumio go-librespot[2141]: time="2025-05-17T02:59: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" May 17 02:59:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:43 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:43 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:45 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:45 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:45 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. May 17 02:59:46 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:46 volumio go-librespot[2189]: go-librespot daemon starting... May 17 02:59:46 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:46 volumio go-librespot[2189]: time="2025-05-17T02:59:46Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:46 volumio go-librespot[2189]: time="2025-05-17T02:59:46Z" level=debug msg="app state loaded" May 17 02:59:46 volumio go-librespot[2189]: time="2025-05-17T02:59:46Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:46 volumio go-librespot[2189]: time="2025-05-17T02:59: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" May 17 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:46 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:46 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:49 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:49 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. May 17 02:59:49 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:49 volumio go-librespot[2211]: go-librespot daemon starting... May 17 02:59:49 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:49 volumio go-librespot[2211]: time="2025-05-17T02:59:49Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:49 volumio go-librespot[2211]: time="2025-05-17T02:59:49Z" level=debug msg="app state loaded" May 17 02:59:49 volumio go-librespot[2211]: time="2025-05-17T02:59:49Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:49 volumio go-librespot[2211]: time="2025-05-17T02:59: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" May 17 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:50 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:50 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:50 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:52 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:52 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. May 17 02:59:53 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:53 volumio go-librespot[2221]: go-librespot daemon starting... May 17 02:59:53 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:53 volumio go-librespot[2221]: time="2025-05-17T02:59:53Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:53 volumio go-librespot[2221]: time="2025-05-17T02:59:53Z" level=debug msg="app state loaded" May 17 02:59:53 volumio go-librespot[2221]: time="2025-05-17T02:59:53Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:53 volumio go-librespot[2221]: time="2025-05-17T02:59:53Z" 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" May 17 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:53 volumio kernel: usb 2-4: new SuperSpeed USB device number 2 using xhci_hcd May 17 02:59:53 volumio kernel: usb 2-4: New USB device found, idVendor=2357, idProduct=0601, bcdDevice=30.00 May 17 02:59:53 volumio kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6 May 17 02:59:53 volumio kernel: usb 2-4: Product: USB 10/100/1000 LAN May 17 02:59:53 volumio kernel: usb 2-4: Manufacturer: TP-Link May 17 02:59:53 volumio kernel: usb 2-4: SerialNumber: 000001 May 17 02:59:53 volumio kernel: usbcore: registered new device driver r8152-cfgselector May 17 02:59:53 volumio kernel: r8152-cfgselector 2-4: reset SuperSpeed USB device number 2 using xhci_hcd May 17 02:59:53 volumio kernel: r8152 2-4:1.0: load rtl8153a-4 v2 02/07/20 successfully May 17 02:59:53 volumio kernel: r8152 2-4:1.0 eth0: v1.12.13 May 17 02:59:53 volumio kernel: usbcore: registered new interface driver r8152 May 17 02:59:53 volumio kernel: usbcore: registered new interface driver cdc_ether May 17 02:59:53 volumio systemd-udevd[2226]: Using default interface naming scheme 'v240'. May 17 02:59:53 volumio dhcpcd[598]: eth0: waiting for carrier May 17 02:59:53 volumio dhcpcd[598]: eth0: carrier acquired May 17 02:59:53 volumio systemd-udevd[2226]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. May 17 02:59:53 volumio dhcpcd[598]: DUID 00:04:32:51:5c:79:db:1c:49:e2:69:6f:1c:69:7a:03:e3:fa May 17 02:59:53 volumio dhcpcd[598]: eth0: IAID e3:c4:5d:6d May 17 02:59:53 volumio dhcpcd[598]: eth0: adding address fe80::5291:e3ff:fec4:5d6d May 17 02:59:53 volumio dhcpcd[598]: ipv6_addaddr1: Permission denied May 17 02:59:53 volumio dhcpcd[598]: eth0: probing address 192.168.2.7/24 May 17 02:59:53 volumio dhcpcd[598]: eth0: carrier lost May 17 02:59:53 volumio systemd[1]: Found device USB_10_100_1000_LAN. May 17 02:59:53 volumio systemd[1]: Started ifup for eth0. May 17 02:59:53 volumio sh[2257]: command failed: No such device (-19) May 17 02:59:53 volumio sh[2257]: eth0=eth0 May 17 02:59:55 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 02:59:55 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 02:59:55 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 02:59:55 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:55 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. May 17 02:59:56 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:56 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:56 volumio go-librespot[2307]: go-librespot daemon starting... May 17 02:59:56 volumio go-librespot[2307]: time="2025-05-17T02:59:56Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:56 volumio go-librespot[2307]: time="2025-05-17T02:59:56Z" level=debug msg="app state loaded" May 17 02:59:56 volumio go-librespot[2307]: time="2025-05-17T02:59:56Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:56 volumio go-librespot[2307]: time="2025-05-17T02:59: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" May 17 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 02:59:58 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 02:59:58 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 02:59:58 volumio dhcpcd[598]: eth0: removing interface May 17 02:59:58 volumio kernel: r8152-cfgselector 2-4: USB disconnect, device number 2 May 17 02:59:58 volumio kernel: xhci_hcd 0000:00:14.0: WARN Set TR Deq Ptr cmd failed due to incorrect slot or ep state. May 17 02:59:58 volumio kernel: r8152 2-4:1.0 eth0: Stop submitting intr, status -108 May 17 02:59:58 volumio systemd[1]: Stopping ifup for eth0... May 17 02:59:59 volumio systemd[1]: ifup@eth0.service: Succeeded. May 17 02:59:59 volumio systemd[1]: Stopped ifup for eth0. May 17 02:59:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 02:59:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. May 17 02:59:59 volumio systemd[1]: Stopped go-librespot Daemon. May 17 02:59:59 volumio go-librespot[2362]: go-librespot daemon starting... May 17 02:59:59 volumio systemd[1]: Started go-librespot Daemon. May 17 02:59:59 volumio go-librespot[2362]: time="2025-05-17T02:59:59Z" level=info msg="running go-librespot 0.2.0" May 17 02:59:59 volumio go-librespot[2362]: time="2025-05-17T02:59:59Z" level=debug msg="app state loaded" May 17 02:59:59 volumio go-librespot[2362]: time="2025-05-17T02:59:59Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 02:59:59 volumio go-librespot[2362]: time="2025-05-17T02:59: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" May 17 02:59:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 02:59:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:00 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 03:00:00 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 03:00:00 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 03:00:01 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:01 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78. May 17 03:00:02 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:02 volumio go-librespot[2372]: go-librespot daemon starting... May 17 03:00:02 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:02 volumio go-librespot[2372]: time="2025-05-17T03:00:02Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:02 volumio go-librespot[2372]: time="2025-05-17T03:00:02Z" level=debug msg="app state loaded" May 17 03:00:02 volumio go-librespot[2372]: time="2025-05-17T03:00:02Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:02 volumio go-librespot[2372]: time="2025-05-17T03:00: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" May 17 03:00:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 03:00:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:04 volumio kernel: usb 2-4: new SuperSpeed USB device number 3 using xhci_hcd May 17 03:00:04 volumio kernel: usb 2-4: New USB device found, idVendor=2357, idProduct=0601, bcdDevice=30.00 May 17 03:00:04 volumio kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6 May 17 03:00:04 volumio kernel: usb 2-4: Product: USB 10/100/1000 LAN May 17 03:00:04 volumio kernel: usb 2-4: Manufacturer: TP-Link May 17 03:00:04 volumio kernel: usb 2-4: SerialNumber: 000001 May 17 03:00:04 volumio kernel: cdc_ether 2-4:2.0 eth0: register 'cdc_ether' at usb-0000:00:14.0-4, CDC Ethernet Device, 50:91:e3:c4:5d:6d May 17 03:00:04 volumio kernel: cdc_ether 2-4:2.0 eth0: unregister 'cdc_ether' usb-0000:00:14.0-4, CDC Ethernet Device May 17 03:00:04 volumio dhcpcd[598]: dhcpcd_prestartinterface: eth0: No such device May 17 03:00:04 volumio dhcpcd[598]: eth0: waiting for carrier May 17 03:00:04 volumio dhcpcd[598]: eth0: removing interface May 17 03:00:04 volumio kernel: r8152-cfgselector 2-4: reset SuperSpeed USB device number 3 using xhci_hcd May 17 03:00:04 volumio kernel: r8152 2-4:1.0: load rtl8153a-4 v2 02/07/20 successfully May 17 03:00:04 volumio kernel: r8152 2-4:1.0 eth0: v1.12.13 May 17 03:00:04 volumio systemd-udevd[2377]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. May 17 03:00:04 volumio dhcpcd[598]: eth0: waiting for carrier May 17 03:00:04 volumio dhcpcd[598]: eth0: carrier acquired May 17 03:00:04 volumio dhcpcd[598]: eth0: IAID e3:c4:5d:6d May 17 03:00:04 volumio dhcpcd[598]: eth0: adding address fe80::5291:e3ff:fec4:5d6d May 17 03:00:04 volumio dhcpcd[598]: ipv6_addaddr1: Permission denied May 17 03:00:04 volumio dhcpcd[598]: eth0: probing address 192.168.2.7/24 May 17 03:00:04 volumio dhcpcd[598]: eth0: carrier lost May 17 03:00:04 volumio systemd[1]: Found device /sys/subsystem/net/devices/eth0. May 17 03:00:04 volumio systemd[1]: ifup@eth0.service: Bound to unit sys-subsystem-net-devices-eth0.device, but unit isn't active. May 17 03:00:04 volumio systemd[1]: Dependency failed for ifup for eth0. May 17 03:00:04 volumio systemd[1]: ifup@eth0.service: Job ifup@eth0.service/start failed with result 'dependency'. May 17 03:00:04 volumio systemd-udevd[2398]: Using default interface naming scheme 'v240'. May 17 03:00:04 volumio systemd-udevd[2398]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. May 17 03:00:04 volumio systemd[1]: Found device USB_10_100_1000_LAN. May 17 03:00:04 volumio systemd[1]: Started ifup for eth0. May 17 03:00:04 volumio sh[2436]: command failed: No such device (-19) May 17 03:00:04 volumio sh[2436]: eth0=eth0 May 17 03:00:04 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:04 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:05 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 03:00:05 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 03:00:05 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 03:00:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79. May 17 03:00:06 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:06 volumio go-librespot[2486]: go-librespot daemon starting... May 17 03:00:06 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:06 volumio go-librespot[2486]: time="2025-05-17T03:00:06Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:06 volumio go-librespot[2486]: time="2025-05-17T03:00:06Z" level=debug msg="app state loaded" May 17 03:00:06 volumio go-librespot[2486]: time="2025-05-17T03:00:06Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:06 volumio go-librespot[2486]: time="2025-05-17T03:00:06Z" 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" May 17 03:00:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 03:00:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:07 volumio ntpd[790]: error resolving pool 0.debian.pool.ntp.org: System error (-11) May 17 03:00:07 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:07 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. May 17 03:00:09 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:09 volumio go-librespot[2508]: go-librespot daemon starting... May 17 03:00:09 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:09 volumio go-librespot[2508]: time="2025-05-17T03:00:09Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:09 volumio go-librespot[2508]: time="2025-05-17T03:00:09Z" level=debug msg="app state loaded" May 17 03:00:09 volumio go-librespot[2508]: time="2025-05-17T03:00:09Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:09 volumio go-librespot[2508]: time="2025-05-17T03:00: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" May 17 03:00:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 03:00:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:09 volumio ntpd[790]: error resolving pool 2.debian.pool.ntp.org: System error (-11) May 17 03:00:09 volumio ntpd[790]: error resolving pool 1.debian.pool.ntp.org: System error (-11) May 17 03:00:10 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 03:00:10 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 03:00:10 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 03:00:10 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:10 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:11 volumio ntpd[790]: error resolving pool 3.debian.pool.ntp.org: System error (-11) May 17 03:00:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81. May 17 03:00:12 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:12 volumio go-librespot[2518]: go-librespot daemon starting... May 17 03:00:12 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:12 volumio go-librespot[2518]: time="2025-05-17T03:00:12Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:12 volumio go-librespot[2518]: time="2025-05-17T03:00:12Z" level=debug msg="app state loaded" May 17 03:00:12 volumio go-librespot[2518]: time="2025-05-17T03:00:12Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:12 volumio go-librespot[2518]: time="2025-05-17T03:00: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" May 17 03:00:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 03:00:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:13 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:13 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:15 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 03:00:15 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 03:00:15 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 03:00:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82. May 17 03:00:15 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:15 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:15 volumio go-librespot[2528]: go-librespot daemon starting... May 17 03:00:15 volumio go-librespot[2528]: time="2025-05-17T03:00:15Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:15 volumio go-librespot[2528]: time="2025-05-17T03:00:15Z" level=debug msg="app state loaded" May 17 03:00:15 volumio go-librespot[2528]: time="2025-05-17T03:00:15Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:15 volumio go-librespot[2528]: time="2025-05-17T03:00: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" May 17 03:00:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 03:00:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:16 volumio dhcpcd[598]: eth0: carrier acquired May 17 03:00:16 volumio dhcpcd[598]: eth0: IAID e3:c4:5d:6d May 17 03:00:16 volumio dhcpcd[598]: eth0: probing address 192.168.2.7/24 May 17 03:00:16 volumio kernel: r8152 2-4:1.0 eth0: carrier on May 17 03:00:16 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:16 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:17 volumio dhcpcd[598]: eth0: soliciting an IPv6 router May 17 03:00:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83. May 17 03:00:19 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:19 volumio go-librespot[2548]: go-librespot daemon starting... May 17 03:00:19 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:19 volumio go-librespot[2548]: time="2025-05-17T03:00:19Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:19 volumio go-librespot[2548]: time="2025-05-17T03:00:19Z" level=debug msg="app state loaded" May 17 03:00:19 volumio go-librespot[2548]: time="2025-05-17T03:00:19Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:19 volumio go-librespot[2548]: time="2025-05-17T03:00:19Z" 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" May 17 03:00:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 17 03:00:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 17 03:00:19 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:19 volumio volumio[808]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 17 03:00:20 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 03:00:20 volumio volumio-time-update[576]: volumio-time-update-util: Date not found in response May 17 03:00:20 volumio volumio-time-update[576]: volumio-time-update-util: Retrying in 5 seconds... May 17 03:00:21 volumio dhcpcd[598]: eth0: using static address 192.168.2.7/24 May 17 03:00:21 volumio dhcpcd[598]: eth0: adding route to 192.168.2.0/24 May 17 03:00:21 volumio dhcpcd[598]: eth0: adding default route via 192.168.2.1 May 17 03:00:21 volumio avahi-daemon[577]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.2.7. May 17 03:00:21 volumio avahi-daemon[577]: New relevant interface eth0.IPv4 for mDNS. May 17 03:00:21 volumio avahi-daemon[577]: Registering new address record for 192.168.2.7 on eth0.IPv4. May 17 03:00:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 17 03:00:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. May 17 03:00:22 volumio systemd[1]: Stopped go-librespot Daemon. May 17 03:00:22 volumio systemd[1]: Started go-librespot Daemon. May 17 03:00:22 volumio go-librespot[2576]: go-librespot daemon starting... May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=info msg="running go-librespot 0.2.0" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="app state loaded" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=info msg="api server listening on 127.0.0.1:9879" May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 17 03:00:22 volumio volumio[808]: info: Adding plugin bluetooth to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: Adding plugin multiroom to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: Adding plugin metavolumio to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: Adding plugin cd_controller to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: Adding plugin qobuzconnect to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: Adding plugin smart_inputs to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: Adding plugin tidalconnect to MyMusic Plugins May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=info msg="zeroconf server listening on port 35109" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="obtained new client token: AABIPydC19uvayMNqU1wZb74ou+cmYXMU++ZVBhXiz7DRjQ3JU5gQys1W7WQN9lV046lPqt46OQsfaIKhvTUS7StE8sPSHtqhVXncg3PlKg6vu4esXZ7wC5QsNm7YhQ8l9jfzdrHvdPawI+VbAfscjV1JIWxiFC7n+oyE113WVdp34ByrXqiw0Hz1UglJ+1/oo43y/KethBxvroBf7IzbQLNZhbm9mbsqqGd+1kCk5racy+mIPmmJT5P" May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 17 03:00:22 volumio volumio[808]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 03:00:22 volumio volumio[808]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 03:00:22 volumio volumio[808]: info: Starting MyVolumio Remote Streaming Endpoints May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="connected to ap-gew1.spotify.com:4070" May 17 03:00:22 volumio volumio[808]: info: MyVolumio login type: Token May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 17 03:00:22 volumio volumio[808]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="completed keyexchange" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="completed challenge" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=info msg="authenticated AP as 31qbzhnzo4np7v7hfauhlr6mteau" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=info msg="authenticated Login5 as 31qbzhnzo4np7v7hfauhlr6mteau" May 17 03:00:22 volumio go-librespot[2576]: time="2025-05-17T03:00:22Z" level=debug msg="initializing zeroconf session, username: 31qbzhnzo4np7v7hfauhlr6mteau" May 17 03:00:23 volumio volumio[808]: info: Starting Streaming Service Transparent Proxy May 17 03:00:23 volumio volumio[808]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 17 03:00:23 volumio volumio[808]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 17 03:00:23 volumio volumio[808]: info: Streaming services startup May 17 03:00:23 volumio volumio[808]: info: Starting Streaming Daemon May 17 03:00:23 volumio sudo[2585]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 17 03:00:23 volumio sudo[2585]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 03:00:23 volumio volumio[808]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 17 03:00:23 volumio sudo[2585]: pam_unix(sudo:session): session closed for user root May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="dealer connection opened" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=trace msg="starting accesspoint recv loop" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=trace msg="starting dealer recv loop" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=trace msg="received accesspoint ping" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="received connection id: MDhkZGEzN2ItNzVhYS00YjlmLThkZmUtY2M0YzUyNDJmMGI0K2RlYWxlcit0Y3A6Ly8wYWNhNDEwZi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArQTk5QjdCN0ZCREM3OEQ5NTBCNTMxNzQwMDJGMEYzMjI0RTREOTk4NDBCQkVCOEExQUNFMzlGNzZDNzQxNjhDQQ==" May 17 03:00:23 volumio volumio[808]: info: Initializing connection to go-librespot Websocket May 17 03:00:23 volumio volumio[808]: error: Cannot start Volumio Streaming Daemon May 17 03:00:23 volumio volumio[808]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 17 03:00:23 volumio volumio[808]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=trace msg="received accesspoint pong ack" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="new websocket client" May 17 03:00:23 volumio volumio[808]: info: Connection to go-librespot Websocket established May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="put connect state because NEW_DEVICE" May 17 03:00:23 volumio go-librespot[2576]: time="2025-05-17T03:00:23Z" level=debug msg="update volume to 65535/65535" May 17 03:00:23 volumio volumio[808]: info: Discovery: adding 07a7ee03-8edb-434f-a0ef-d8752f587ade May 17 03:00:23 volumio volumio[808]: info: Discovery: Found device Volumio May 17 03:00:23 volumio volumio[808]: info: CoreCommandRouter::volumioGetState May 17 03:00:23 volumio volumio[808]: info: CorePlayQueue::getTrack 0 May 17 03:00:23 volumio volumio[808]: STREAMING PROXY: Starting server on port 3245 May 17 03:00:23 volumio volumio[808]: Node JS runtime: 14 May 17 03:00:23 volumio volumio[808]: error: MyVolumio Custom Token format not valid, refreshing it May 17 03:00:23 volumio ntpd[790]: Listen normally on 3 eth0 192.168.2.7:123 May 17 03:00:23 volumio ntpd[790]: new interface(s) found: waking up resolver May 17 03:00:24 volumio volumio[808]: info: MyVolumio login type: Token May 17 03:00:24 volumio go-librespot[2576]: time="2025-05-17T03:00:24Z" level=debug msg="put connect state because VOLUME_CHANGED" May 17 03:00:24 volumio go-librespot[2576]: time="2025-05-17T03:00:24Z" level=trace msg="emitting websocket event: volume" May 17 03:00:24 volumio volumio[808]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} May 17 03:00:24 volumio volumio[808]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 May 17 03:00:24 volumio volumio[808]: info: Setting Volumio Volume from Spotify: 100 May 17 03:00:24 volumio volumio[808]: info: VolumeController::SetAlsaVolume100 May 17 03:00:24 volumio volumio[808]: info: CoreStateMachine::pushState May 17 03:00:24 volumio volumio[808]: info: CorePlayQueue::getTrack 0 May 17 03:00:24 volumio volumio[808]: info: CoreCommandRouter::volumioPushState May 17 03:00:24 volumio volumio[808]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 17 03:00:25 volumio volumio[808]: info: MyVolumio token set successfully May 17 03:00:25 volumio volumio[808]: info: MYVOLUMIO: Adding device May 17 03:00:25 volumio volumio[808]: info: MYVOLUMIO: Evaluating Server May 17 03:00:25 volumio volumio[808]: info: MyVolumio status changed May 17 03:00:25 volumio volumio[808]: info: Streaming services startup May 17 03:00:25 volumio volumio[808]: info: Starting Streaming Daemon May 17 03:00:25 volumio volumio[808]: info: Removing browser output: myVolumio user plan is not superstar May 17 03:00:25 volumio volumio[808]: info: Removing audio output: May 17 03:00:25 volumio volumio[808]: info: Stoppping Tunnel 1 May 17 03:00:25 volumio sudo[2614]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 17 03:00:25 volumio sudo[2614]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 03:00:25 volumio sudo[2616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 17 03:00:25 volumio volumio-time-update[576]: volumio-time-update-util: Fetching time from Volumio... May 17 03:00:25 volumio sudo[2614]: pam_unix(sudo:session): session closed for user root May 17 03:00:25 volumio sudo[2616]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 03:00:25 volumio sudo[2616]: pam_unix(sudo:session): session closed for user root May 17 03:00:25 volumio sudo[2625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 17 03:00:25 volumio volumio[808]: error: Cannot start Volumio Streaming Daemon May 17 03:00:25 volumio volumio[808]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 17 03:00:25 volumio volumio[808]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 17 03:00:25 volumio volumio[808]: info: Remote SSH Stopped May 17 03:00:25 volumio sudo[2626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 17 03:00:25 volumio sudo[2625]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 03:00:25 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 03:00:25 volumio sudo[2625]: pam_unix(sudo:session): session closed for user root May 17 03:00:25 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root May 17 03:00:25 volumio volumio-time-update[576]: volumio-time-update-util: Setting system time to: 2025-05-17 03:00:25 May 17 03:00:25 volumio sudo[2632]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-17 03:00:25 May 17 03:00:25 volumio sudo[2632]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 03:00:25 volumio dbus-daemon[588]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=2633 comm="timedatectl set-time 2025-05-17 03:00:25 ") May 17 03:00:25 volumio systemd[1]: Starting Time & Date Service... May 17 03:00:25 volumio dbus-daemon[588]: [system] Successfully activated service 'org.freedesktop.timedate1' May 17 03:00:25 volumio systemd[1]: Started Time & Date Service. May 17 03:00:25 volumio systemd-timedated[2634]: Changed local time to Sat May 17 03:00:25 2025 May 17 03:00:25 volumio sudo[2632]: pam_unix(sudo:session): session closed for user root May 17 03:00:25 volumio volumio-time-update[576]: volumio-time-update-util: System time updated successfully. May 17 03:00:25 volumio systemd[1]: Started Volumio Time Update Utility. May 17 03:00:25 volumio systemd[1]: Reached target Multi-User System. May 17 03:00:25 volumio systemd[1]: Reached target Graphical Interface. May 17 03:00:25 volumio volumio[808]: verbose: New Socket.io Connection to 192.168.2.7 from 192.168.2.8 UA: Mozilla/5.0 (X11; Linux x86_64; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 4 May 17 03:00:25 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 17 03:00:25 volumio volumio[808]: error: Failed to ping endpoint as1.myvolumio.org : unknown error May 17 03:00:25 volumio volumio[808]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 03:00:25 volumio volumio[808]: Error: Unable to resolve or reject the same promise twice May 17 03:00:25 volumio volumio[808]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 17 03:00:25 volumio volumio[808]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) May 17 03:00:25 volumio volumio[808]: at Socket.emit (events.js:412:35) May 17 03:00:25 volumio volumio[808]: at endReadableNT (internal/streams/readable.js:1333:12) May 17 03:00:25 volumio volumio[808]: at processTicksAndRejections (internal/process/task_queues.js:82:21) May 17 03:00:25 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 17 03:00:25 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 17 03:00:25 volumio systemd[1]: Startup finished in 7.730s (firmware) + 568ms (loader) + 5.637s (kernel) + 4min 43.130s (userspace) = 4min 57.066s. May 17 03:00:25 volumio volumio[808]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 03:00:25 volumio sudo[2646]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-17 02:59 May 17 03:00:25 volumio sudo[2646]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:50:12 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="39b0f8c200b2dcadf117e189b4b3632d"