-- Logs begin at Mon 2025-02-17 06:26:06 UTC, end at Mon 2025-02-17 06:55:45 UTC. -- Feb 17 06:54:01 volumio ntpd[955]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Feb 17 06:54:03 volumio go-librespot[6857]: time="2025-02-17T06:54:03Z" 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" Feb 17 06:54:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 06:54:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 06:54:04 volumio volumio-time-update[784]: volumio-time-update-util: Fetching time from Volumio... Feb 17 06:54:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 17 06:54:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Feb 17 06:54:06 volumio systemd[1]: Stopped go-librespot Daemon. Feb 17 06:54:06 volumio systemd[1]: Started go-librespot Daemon. Feb 17 06:54:06 volumio go-librespot[6904]: go-librespot daemon starting... Feb 17 06:54:06 volumio go-librespot[6904]: time="2025-02-17T06:54:06Z" level=info msg="running go-librespot 0.2.0" Feb 17 06:54:06 volumio go-librespot[6904]: time="2025-02-17T06:54:06Z" level=debug msg="app state loaded" Feb 17 06:54:06 volumio go-librespot[6904]: time="2025-02-17T06:54:06Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 06:54:16 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 17 06:54:21 volumio ntpd[955]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Feb 17 06:54:24 volumio volumio-time-update[784]: volumio-time-update-util: Date not found in response Feb 17 06:54:24 volumio volumio-time-update[784]: volumio-time-update-util: Retrying in 5 seconds... Feb 17 06:54:27 volumio go-librespot[6904]: time="2025-02-17T06:54: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" Feb 17 06:54:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 06:54:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 06:54:29 volumio volumio-time-update[784]: volumio-time-update-util: Fetching time from Volumio... Feb 17 06:54:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 17 06:54:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Feb 17 06:54:30 volumio systemd[1]: Stopped go-librespot Daemon. Feb 17 06:54:30 volumio systemd[1]: Started go-librespot Daemon. Feb 17 06:54:30 volumio go-librespot[7013]: go-librespot daemon starting... Feb 17 06:54:30 volumio go-librespot[7013]: time="2025-02-17T06:54:30Z" level=info msg="running go-librespot 0.2.0" Feb 17 06:54:30 volumio go-librespot[7013]: time="2025-02-17T06:54:30Z" level=debug msg="app state loaded" Feb 17 06:54:30 volumio go-librespot[7013]: time="2025-02-17T06:54:30Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 06:54:41 volumio ntpd[955]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Feb 17 06:54:50 volumio volumio-time-update[784]: volumio-time-update-util: Date not found in response Feb 17 06:54:50 volumio volumio-time-update[784]: volumio-time-update-util: Retrying in 5 seconds... Feb 17 06:54:50 volumio go-librespot[7013]: time="2025-02-17T06:54:50Z" 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" Feb 17 06:54:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 06:54:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 06:54:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 17 06:54:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Feb 17 06:54:53 volumio systemd[1]: Stopped go-librespot Daemon. Feb 17 06:54:53 volumio systemd[1]: Started go-librespot Daemon. Feb 17 06:54:53 volumio go-librespot[7061]: go-librespot daemon starting... Feb 17 06:54:53 volumio go-librespot[7061]: time="2025-02-17T06:54:53Z" level=info msg="running go-librespot 0.2.0" Feb 17 06:54:53 volumio go-librespot[7061]: time="2025-02-17T06:54:53Z" level=debug msg="app state loaded" Feb 17 06:54:53 volumio go-librespot[7061]: time="2025-02-17T06:54:53Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 06:54:55 volumio volumio-time-update[784]: volumio-time-update-util: Fetching time from Volumio... Feb 17 06:54:56 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 17 06:55:01 volumio ntpd[955]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Feb 17 06:55:13 volumio go-librespot[7061]: time="2025-02-17T06:55:13Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 17 06:55:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 06:55:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 06:55:15 volumio volumio-time-update[784]: volumio-time-update-util: Date not found in response Feb 17 06:55:15 volumio volumio-time-update[784]: volumio-time-update-util: Retrying in 5 seconds... Feb 17 06:55:16 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 17 06:55:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 17 06:55:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Feb 17 06:55:16 volumio systemd[1]: Stopped go-librespot Daemon. Feb 17 06:55:16 volumio systemd[1]: Started go-librespot Daemon. Feb 17 06:55:16 volumio go-librespot[7197]: go-librespot daemon starting... Feb 17 06:55:16 volumio go-librespot[7197]: time="2025-02-17T06:55:16Z" level=info msg="running go-librespot 0.2.0" Feb 17 06:55:16 volumio go-librespot[7197]: time="2025-02-17T06:55:16Z" level=debug msg="app state loaded" Feb 17 06:55:16 volumio go-librespot[7197]: time="2025-02-17T06:55:16Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 06:55:17 volumio dhcpcd[866]: eth0: carrier acquired Feb 17 06:55:17 volumio kernel: e1000e 0000:00:19.0 eth0: NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx Feb 17 06:55:17 volumio dhcpcd[866]: eth0: IAID cc:b8:b4:9c Feb 17 06:55:17 volumio dhcpcd[866]: eth0: adding address fe80::b8cc:7e52:f3d8:9d59 Feb 17 06:55:17 volumio dhcpcd[866]: ipv6_addaddr1: Permission denied Feb 17 06:55:17 volumio dhcpcd[866]: eth0: soliciting an IPv6 router Feb 17 06:55:18 volumio ifplugd(eth0)[935]: Link beat detected. Feb 17 06:55:18 volumio ifplugd(eth0)[935]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Feb 17 06:55:18 volumio dhcpcd[7231]: sending commands to master dhcpcd process Feb 17 06:55:18 volumio ifplugd(eth0)[935]: client: sending commands to master dhcpcd process Feb 17 06:55:18 volumio dhcpcd[866]: control command: /sbin/dhcpcd eth0 Feb 17 06:55:18 volumio ifplugd(eth0)[935]: Program executed successfully. Feb 17 06:55:18 volumio dhcpcd[866]: eth0: rebinding lease of 192.168.1.185 Feb 17 06:55:20 volumio volumio-time-update[784]: volumio-time-update-util: Fetching time from Volumio... Feb 17 06:55:21 volumio ntpd[955]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Feb 17 06:55:23 volumio dhcpcd[866]: eth0: probing for an IPv4LL address Feb 17 06:55:23 volumio dhcpcd[866]: eth0: DHCP lease expired Feb 17 06:55:23 volumio dhcpcd[866]: eth0: soliciting a DHCP lease Feb 17 06:55:27 volumio dhcpcd[866]: eth0: probing address 192.168.1.185/24 Feb 17 06:55:28 volumio dhcpcd[866]: eth0: using IPv4LL address 169.254.126.48 Feb 17 06:55:28 volumio dhcpcd[866]: eth0: adding route to 169.254.0.0/16 Feb 17 06:55:28 volumio dhcpcd[866]: eth0: adding default route Feb 17 06:55:28 volumio avahi-daemon[779]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.126.48. Feb 17 06:55:28 volumio dhcpcd[866]: wlan0: deleting default route Feb 17 06:55:28 volumio avahi-daemon[779]: New relevant interface eth0.IPv4 for mDNS. Feb 17 06:55:28 volumio avahi-daemon[779]: Registering new address record for 169.254.126.48 on eth0.IPv4. Feb 17 06:55:30 volumio ntpd[955]: Listen normally on 5 eth0 169.254.126.48:123 Feb 17 06:55:30 volumio ntpd[955]: new interface(s) found: waking up resolver Feb 17 06:55:30 volumio volumio[1062]: info: Volumio Network Manager: Network status updated: 1 Feb 17 06:55:32 volumio dhcpcd[866]: eth0: leased 192.168.1.185 for 86400 seconds Feb 17 06:55:32 volumio dhcpcd[866]: eth0: adding route to 192.168.1.0/24 Feb 17 06:55:32 volumio dhcpcd[866]: eth0: changing default route via 192.168.1.1 Feb 17 06:55:32 volumio avahi-daemon[779]: Registering new address record for 192.168.1.185 on eth0.IPv4. Feb 17 06:55:32 volumio dnsmasq[1116]: reading /etc/resolv.conf Feb 17 06:55:32 volumio dnsmasq[1116]: using nameserver 192.168.1.1#53 Feb 17 06:55:32 volumio dnsmasq[1116]: using nameserver 208.67.222.222#53 Feb 17 06:55:32 volumio dnsmasq[1116]: using nameserver 208.67.220.220#53 Feb 17 06:55:32 volumio ntpd[955]: ntpd exiting on signal 15 (Terminated) Feb 17 06:55:32 volumio systemd[1]: Stopping Network Time Service... Feb 17 06:55:32 volumio systemd[1]: ntp.service: Succeeded. Feb 17 06:55:32 volumio systemd[1]: Stopped Network Time Service. Feb 17 06:55:32 volumio systemd[1]: Starting Network Time Service... Feb 17 06:55:32 volumio ntpd[7404]: ntpd 4.2.8p12@1.3728-o (1): Starting Feb 17 06:55:32 volumio ntpd[7404]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Feb 17 06:55:32 volumio systemd[1]: Started Network Time Service. Feb 17 06:55:32 volumio ntpd[7410]: proto: precision = 0.074 usec (-24) Feb 17 06:55:32 volumio dhcpcd[866]: eth0: deleting route to 169.254.0.0/16 Feb 17 06:55:32 volumio ntpd[7410]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Feb 17 06:55:32 volumio avahi-daemon[779]: Withdrawing address record for 169.254.126.48 on eth0. Feb 17 06:55:32 volumio avahi-daemon[779]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.126.48. Feb 17 06:55:32 volumio avahi-daemon[779]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.185. Feb 17 06:55:32 volumio ntpd[7410]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Feb 17 06:55:32 volumio ntpd[7410]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 783 days ago Feb 17 06:55:32 volumio ntpd[7410]: Listen and drop on 0 v6wildcard [::]:123 Feb 17 06:55:32 volumio ntpd[7410]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Feb 17 06:55:32 volumio ntpd[7410]: Listen normally on 2 lo 127.0.0.1:123 Feb 17 06:55:32 volumio ntpd[7410]: Listen normally on 3 eth0 192.168.1.185:123 Feb 17 06:55:32 volumio ntpd[7410]: Listen normally on 4 wlan0 192.168.211.1:123 Feb 17 06:55:32 volumio ntpd[7410]: Listen normally on 5 wlan0 169.254.206.39:123 Feb 17 06:55:32 volumio ntpd[7410]: Listening on routing socket on fd #22 for interface updates Feb 17 06:55:32 volumio ntpd[7410]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 17 06:55:32 volumio ntpd[7410]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 17 06:55:33 volumio ntpd[7410]: Soliciting pool server 213.222.217.11 Feb 17 06:55:34 volumio ntpd[7410]: Soliciting pool server 150.254.65.62 Feb 17 06:55:34 volumio ntpd[7410]: Soliciting pool server 194.29.130.252 Feb 17 06:55:35 volumio ntpd[7410]: Soliciting pool server 213.222.217.10 Feb 17 06:55:35 volumio ntpd[7410]: Soliciting pool server 193.25.222.136 Feb 17 06:55:35 volumio ntpd[7410]: Soliciting pool server 195.46.37.22 Feb 17 06:55:36 volumio ntpd[7410]: Soliciting pool server 51.77.52.155 Feb 17 06:55:36 volumio ntpd[7410]: Soliciting pool server 213.135.57.60 Feb 17 06:55:36 volumio ntpd[7410]: Soliciting pool server 89.25.168.148 Feb 17 06:55:36 volumio ntpd[7410]: Soliciting pool server 51.68.141.5 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Feb 17 06:55:36 volumio go-librespot[7197]: time="2025-02-17T06:55:36Z" level=debug msg="new websocket client" Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Feb 17 06:55:36 volumio volumio[1062]: info: Connection to go-librespot Websocket established Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 29 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 30 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 31 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 32 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 33 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 34 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 35 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 36 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 37 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 38 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 39 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 40 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 41 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 42 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 43 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 44 Feb 17 06:55:36 volumio go-librespot[7197]: time="2025-02-17T06:55: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" Feb 17 06:55:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 06:55:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 06:55:36 volumio volumio[1062]: info: Connection to go-librespot Websocket closed Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 45 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 46 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 47 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 48 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 49 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 50 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 51 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 52 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 53 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 54 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 55 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 56 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 57 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 58 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 59 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 60 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 61 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 62 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 63 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 64 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 65 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 66 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 67 Feb 17 06:55:36 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 68 Feb 17 06:55:36 volumio volumio[1062]: info: CoreCommandRouter::volumioGetState Feb 17 06:55:36 volumio volumio[1062]: info: CorePlayQueue::getTrack 0 Feb 17 06:55:36 volumio volumio[1062]: info: Discovery: this is already registered, 75411a6e-52f1-48c4-8527-c5a8fb56aebc Feb 17 06:55:36 volumio volumio[1062]: info: Discovery: Found device Volumio Feb 17 06:55:36 volumio volumio[1062]: info: CoreCommandRouter::volumioGetState Feb 17 06:55:36 volumio volumio[1062]: info: CorePlayQueue::getTrack 0 Feb 17 06:55:37 volumio ntpd[7410]: Soliciting pool server 89.161.47.132 Feb 17 06:55:37 volumio ntpd[7410]: Soliciting pool server 178.215.228.24 Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 06:55:37 volumio volumio[1062]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 06:55:37 volumio volumio[1062]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 06:55:37 volumio volumio[1062]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 06:55:37 volumio volumio[1062]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 06:55:37 volumio volumio[1062]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 06:55:37 volumio volumio[1062]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 06:55:37 volumio volumio[1062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 06:55:37 volumio volumio[1062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 06:55:37 volumio volumio[1062]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 06:55:37 volumio volumio[1062]: info: MyVolumio login type: Token Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 06:55:37 volumio volumio[1062]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 06:55:38 volumio volumio[1062]: info: Starting Streaming Service Transparent Proxy Feb 17 06:55:38 volumio volumio[1062]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 06:55:38 volumio volumio[1062]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 06:55:38 volumio volumio[1062]: info: Streaming services startup Feb 17 06:55:38 volumio volumio[1062]: info: Starting Streaming Daemon Feb 17 06:55:38 volumio sudo[7456]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 06:55:38 volumio sudo[7456]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 17 06:55:38 volumio ntpd[7410]: Soliciting pool server 156.17.20.254 Feb 17 06:55:38 volumio ntpd[7410]: Soliciting pool server 85.115.212.250 Feb 17 06:55:38 volumio sudo[7456]: pam_unix(sudo:session): session closed for user root Feb 17 06:55:38 volumio volumio[1062]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 06:55:38 volumio volumio[1062]: error: Cannot start Volumio Streaming Daemon Feb 17 06:55:38 volumio volumio[1062]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 06:55:38 volumio volumio[1062]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 06:55:38 volumio volumio[1062]: STREAMING PROXY: Starting server on port 3245 Feb 17 06:55:38 volumio volumio[1062]: Node JS runtime: 14 Feb 17 06:55:38 volumio volumio[1062]: error: MyVolumio Custom Token format not valid, refreshing it Feb 17 06:55:39 volumio volumio[1062]: info: MyVolumio login type: Token Feb 17 06:55:39 volumio ntpd[7410]: Soliciting pool server 2001:41d0:601:1100::649c Feb 17 06:55:39 volumio volumio[1062]: info: Getting Spotify volume Feb 17 06:55:39 volumio volumio[1062]: (node:1062) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 06:55:39 volumio volumio[1062]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 17 06:55:39 volumio volumio[1062]: (node:1062) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 6) Feb 17 06:55:39 volumio volumio[1062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 69 Feb 17 06:55:39 volumio volumio[1062]: info: CoreCommandRouter::volumioGetState Feb 17 06:55:39 volumio volumio[1062]: info: CorePlayQueue::getTrack 0 Feb 17 06:55:39 volumio volumio[1062]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 17 06:55:39 volumio volumio[1062]: info: Initializing connection to go-librespot Websocket Feb 17 06:55:39 volumio volumio[1062]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 06:55:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 17 06:55:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Feb 17 06:55:39 volumio systemd[1]: Stopped go-librespot Daemon. Feb 17 06:55:39 volumio systemd[1]: Started go-librespot Daemon. Feb 17 06:55:39 volumio go-librespot[7467]: go-librespot daemon starting... Feb 17 06:55:39 volumio go-librespot[7467]: time="2025-02-17T06:55:39Z" level=info msg="running go-librespot 0.2.0" Feb 17 06:55:39 volumio go-librespot[7467]: time="2025-02-17T06:55:39Z" level=debug msg="app state loaded" Feb 17 06:55:39 volumio go-librespot[7467]: time="2025-02-17T06:55:39Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 06:55:40 volumio volumio-time-update[784]: volumio-time-update-util: Date not found in response Feb 17 06:55:40 volumio volumio-time-update[784]: volumio-time-update-util: Retrying in 5 seconds... Feb 17 06:55:40 volumio volumio[1062]: info: MyVolumio token set successfully Feb 17 06:55:40 volumio volumio[1062]: info: MYVOLUMIO: Adding device Feb 17 06:55:40 volumio volumio[1062]: info: MYVOLUMIO: Evaluating Server Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=info msg="zeroconf server listening on port 38073" Feb 17 06:55:40 volumio volumio[1062]: info: MyVolumio status changed Feb 17 06:55:40 volumio volumio[1062]: info: Streaming services startup Feb 17 06:55:40 volumio volumio[1062]: info: Starting Streaming Daemon Feb 17 06:55:40 volumio volumio[1062]: info: Removing browser output: myVolumio user plan is not superstar Feb 17 06:55:40 volumio volumio[1062]: info: Removing audio output: Feb 17 06:55:40 volumio volumio[1062]: info: Stoppping Tunnel 1 Feb 17 06:55:40 volumio sudo[7506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 06:55:40 volumio sudo[7506]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 17 06:55:40 volumio sudo[7506]: pam_unix(sudo:session): session closed for user root Feb 17 06:55:40 volumio volumio[1062]: error: Cannot start Volumio Streaming Daemon Feb 17 06:55:40 volumio volumio[1062]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 06:55:40 volumio volumio[1062]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 06:55:40 volumio sudo[7509]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 17 06:55:40 volumio sudo[7509]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 17 06:55:40 volumio sudo[7509]: pam_unix(sudo:session): session closed for user root Feb 17 06:55:40 volumio volumio[1062]: info: Remote SSH Stopped Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="obtained new client token: AABd7QleuAj48AbtDLsov7iRzJrMLvJNyFPHUkEWhiFU6selFZx7poYt507QrjJnsA0nJrddMSbJZI8uUcX5BkHJv3IBBBXOFhcUFVnzAMnfO1/J9+vV0HBSJiMv8kluuxAXr63DzGeyWZPDSs5TwIyH69zwns0G4Yp5me6ywxqkVtFb//zpecMjEOxNZnaiyCnrFd73HmQenGzkBtZU70dShVXW9qNDycN38e4k7td0t/1s2RZkpQ77" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="completed keyexchange" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="completed challenge" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=info msg="authenticated AP as 31pqtovvgch2ghvtisbfoawns7fi" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=info msg="authenticated Login5 as 31pqtovvgch2ghvtisbfoawns7fi" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="initializing zeroconf session, username: 31pqtovvgch2ghvtisbfoawns7fi" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="dealer connection opened" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=trace msg="starting accesspoint recv loop" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=trace msg="starting dealer recv loop" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=trace msg="received accesspoint ping" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="received connection id: NjUwYjVlMDEtODc0ZS00MGZiLWI2MzAtZjhiMTRmZmUwMTAxK2RlYWxlcit0Y3A6Ly8wYWNhNTk5NS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNTQ3ODRGNUJCRUJBM0MyQTMwNjNBQTQ3RjIyQUEyNEQ0MzYzMUQ3Q0NEOEUxNjY3MTQwRjZGNEU2NjZENTQ2MA==" Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=trace msg="received accesspoint pong ack" Feb 17 06:55:40 volumio volumio[1062]: info: Setting Geolocation for MyVolumio to eu4 Feb 17 06:55:40 volumio volumio[1062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 06:55:40 volumio volumio[1062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 06:55:40 volumio volumio[1062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 06:55:40 volumio go-librespot[7467]: time="2025-02-17T06:55:40Z" level=debug msg="put connect state because NEW_DEVICE" Feb 17 06:55:41 volumio volumio[1062]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 17 06:55:41 volumio ntpd[7410]: receive: Unexpected origin timestamp 0xeb5d5bed.26575c36 does not match aorg 0000000000.00000000 from server@195.46.37.22 xmt 0xeb5d5bed.b7197462 Feb 17 06:55:42 volumio volumio[1062]: info: Updating MyVolumio device info Feb 17 06:55:42 volumio volumio[1062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 06:55:42 volumio volumio[1062]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 17 06:55:43 volumio volumio[1062]: info: Initializing connection to go-librespot Websocket Feb 17 06:55:43 volumio go-librespot[7467]: time="2025-02-17T06:55:43Z" level=debug msg="new websocket client" Feb 17 06:55:43 volumio volumio[1062]: info: Connection to go-librespot Websocket established Feb 17 06:55:45 volumio volumio-time-update[784]: volumio-time-update-util: Fetching time from Volumio... Feb 17 06:55:45 volumio volumio[1062]: info: MYVOLUMIO: Adding device Feb 17 06:55:45 volumio volumio[1062]: info: MYVOLUMIO: Evaluating Server Feb 17 06:55:45 volumio volumio-time-update[784]: volumio-time-update-util: Setting system time to: 2025-02-17 06:55:45 Feb 17 06:55:45 volumio sudo[7516]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-02-17 06:55:45 Feb 17 06:55:45 volumio sudo[7516]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 17 06:55:45 volumio dbus-daemon[776]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.16' (uid=0 pid=7517 comm="timedatectl set-time 2025-02-17 06:55:45 ") Feb 17 06:55:45 volumio systemd[1]: Starting Time & Date Service... Feb 17 06:55:45 volumio dbus-daemon[776]: [system] Successfully activated service 'org.freedesktop.timedate1' Feb 17 06:55:45 volumio systemd[1]: Started Time & Date Service. Feb 17 06:55:45 volumio systemd-timedated[7518]: Changed local time to Mon Feb 17 06:55:45 2025 Feb 17 06:55:45 volumio sudo[7516]: pam_unix(sudo:session): session closed for user root Feb 17 06:55:45 volumio volumio-time-update[784]: volumio-time-update-util: System time updated successfully. Feb 17 06:55:45 volumio systemd[1]: Started Volumio Time Update Utility. Feb 17 06:55:45 volumio systemd[1]: Reached target Multi-User System. Feb 17 06:55:45 volumio systemd[1]: Reached target Graphical Interface. Feb 17 06:55:45 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 17 06:55:45 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 17 06:55:45 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 17 06:55:45 volumio systemd[1]: Startup finished in 9.471s (kernel) + 29min 39.612s (userspace) = 29min 49.083s. Feb 17 06:55:45 volumio volumio[1062]: error: Failed to ping endpoint eu2.myvolumio.org : unknown error Feb 17 06:55:45 volumio volumio[1062]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 06:55:45 volumio volumio[1062]: Error: Unable to resolve or reject the same promise twice Feb 17 06:55:45 volumio volumio[1062]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Feb 17 06:55:45 volumio volumio[1062]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Feb 17 06:55:45 volumio volumio[1062]: at Socket.emit (events.js:400:28) Feb 17 06:55:45 volumio volumio[1062]: at addChunk (internal/streams/readable.js:293:12) Feb 17 06:55:45 volumio volumio[1062]: at readableAddChunk (internal/streams/readable.js:267:9) Feb 17 06:55:45 volumio volumio[1062]: at Socket.Readable.push (internal/streams/readable.js:206:10) Feb 17 06:55:45 volumio volumio[1062]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Feb 17 06:55:45 volumio volumio[1062]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 06:55:45 volumio sudo[7545]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-17 06:54 Feb 17 06:55:45 volumio sudo[7545]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"