-- Logs begin at Mon 2025-04-14 16:28:50 CEST, end at Mon 2025-04-14 16:31:51 CEST. -- Apr 14 16:30:04 volumio volumio[1056]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.799&uuid=7d1787fcb539ef130004eea58f2dd2a8" http://updates.volumio.org/downloader-v1/track-device Apr 14 16:30:04 volumio volumio[1056]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 14 16:30:04 volumio volumio[1056]: Dload Upload Total Spent Left Speed Apr 14 16:30:04 volumio volumio[1056]: [1.6K blob data] Apr 14 16:30:04 volumio volumio[1056]: retrying in 5 seconds, trial 2 Apr 14 16:30:04 volumio volumio[1056]: info: Volumio Calling Home Apr 14 16:30:15 volumio go-librespot[1724]: time="2025-04-14T16:30:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 14 16:30:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 16:30:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 16:30:17 volumio ntpd[954]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 14 16:30:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 14 16:30:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Apr 14 16:30:19 volumio systemd[1]: Stopped go-librespot Daemon. Apr 14 16:30:19 volumio systemd[1]: Started go-librespot Daemon. Apr 14 16:30:19 volumio go-librespot[1783]: Librespot-go daemon starting... Apr 14 16:30:19 volumio go-librespot[1783]: time="2025-04-14T16:30:19+02:00" level=info msg="generated new device id: cd4c06786358ca2b232f9fabfb1137fec9eeae2d" Apr 14 16:30:19 volumio go-librespot[1783]: time="2025-04-14T16:30:19+02:00" level=debug msg="stored credentials found for 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:30:19 volumio volumio-time-update[776]: volumio-time-update-util: Date not found in response Apr 14 16:30:19 volumio volumio-time-update[776]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 16:30:21 volumio dhcpcd[1445]: eth0: offered 192.168.178.17 from 192.168.178.1 Apr 14 16:30:21 volumio dhcpcd[1445]: eth0: probing address 192.168.178.17/24 Apr 14 16:30:21 volumio dhcpcd[1409]: eth0: offered 192.168.178.17 from 192.168.178.1 Apr 14 16:30:21 volumio dhcpcd[1409]: eth0: probing address 192.168.178.17/24 Apr 14 16:30:24 volumio volumio-time-update[776]: volumio-time-update-util: Fetching time from Volumio... Apr 14 16:30:26 volumio dhcpcd[1445]: eth0: leased 192.168.178.17 for 20 seconds Apr 14 16:30:26 volumio avahi-daemon[774]: Registering new address record for 192.168.178.17 on eth0.IPv4. Apr 14 16:30:26 volumio dhcpcd[1445]: eth0: adding route to 192.168.178.0/24 Apr 14 16:30:26 volumio dhcpcd[1445]: eth0: changing default route via 192.168.178.1 Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: deleted default route Apr 14 16:30:26 volumio dnsmasq[1086]: reading /etc/resolv.conf Apr 14 16:30:26 volumio dnsmasq[1086]: using nameserver 192.168.178.1#53 Apr 14 16:30:26 volumio dnsmasq[1086]: using nameserver 208.67.222.222#53 Apr 14 16:30:26 volumio dnsmasq[1086]: using nameserver 208.67.220.220#53 Apr 14 16:30:26 volumio ntpd[954]: ntpd exiting on signal 15 (Terminated) Apr 14 16:30:26 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:30:26 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:30:26 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:30:26 volumio systemd[1]: Starting Network Time Service... Apr 14 16:30:26 volumio ntpd[1828]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:30:26 volumio ntpd[1828]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:30:26 volumio systemd[1]: Started Network Time Service. Apr 14 16:30:26 volumio ntpd[1834]: proto: precision = 0.078 usec (-24) Apr 14 16:30:26 volumio dhcpcd[1445]: eth0: deleting route to 169.254.0.0/16 Apr 14 16:30:26 volumio avahi-daemon[774]: Withdrawing address record for 169.254.129.155 on eth0. Apr 14 16:30:26 volumio ntpd[1834]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:30:26 volumio avahi-daemon[774]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.129.155. Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: deleted route to 169.254.0.0/16 Apr 14 16:30:26 volumio avahi-daemon[774]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.17. Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: adding route to 169.254.0.0/16 Apr 14 16:30:26 volumio dhcpcd[1409]: if_route (ADD): Invalid argument Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: adding default route Apr 14 16:30:26 volumio dhcpcd[1409]: if_route (ADD): Invalid argument Apr 14 16:30:26 volumio ntpd[1834]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:30:26 volumio ntpd[1834]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:30:26 volumio ntpd[1834]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:30:26 volumio ntpd[1834]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:30:26 volumio ntpd[1834]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:30:26 volumio ntpd[1834]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:30:26 volumio ntpd[1834]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:30:26 volumio ntpd[1834]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:30:26 volumio ntpd[1834]: Listening on routing socket on fd #22 for interface updates Apr 14 16:30:26 volumio ntpd[1834]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:26 volumio ntpd[1834]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: leased 192.168.178.17 for 20 seconds Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: adding route to 192.168.178.0/24 Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: adding default route via 192.168.178.1 Apr 14 16:30:26 volumio dhcpcd[1409]: eth0: adding route to 169.254.0.0/16 Apr 14 16:30:26 volumio dhcpcd[1409]: if_route (ADD): Invalid argument Apr 14 16:30:26 volumio ntpd[1834]: ntpd exiting on signal 15 (Terminated) Apr 14 16:30:26 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:30:26 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:30:26 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:30:26 volumio systemd[1]: Starting Network Time Service... Apr 14 16:30:26 volumio ntpd[1882]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:30:26 volumio ntpd[1882]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:30:26 volumio systemd[1]: Started Network Time Service. Apr 14 16:30:26 volumio ntpd[1888]: proto: precision = 0.063 usec (-24) Apr 14 16:30:26 volumio ntpd[1888]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:30:26 volumio ntpd[1888]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:30:26 volumio ntpd[1888]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:30:26 volumio ntpd[1888]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:30:26 volumio ntpd[1888]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:30:26 volumio ntpd[1888]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:30:26 volumio ntpd[1888]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:30:26 volumio ntpd[1888]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:30:26 volumio ntpd[1888]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:30:26 volumio ntpd[1888]: Listening on routing socket on fd #22 for interface updates Apr 14 16:30:26 volumio ntpd[1888]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:26 volumio ntpd[1888]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:34 volumio go-librespot[1783]: time="2025-04-14T16:30:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 14 16:30:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 16:30:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 16:30:36 volumio ntpd[1888]: ntpd exiting on signal 15 (Terminated) Apr 14 16:30:36 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:30:36 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:30:36 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:30:36 volumio systemd[1]: Starting Network Time Service... Apr 14 16:30:36 volumio ntpd[1953]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:30:36 volumio ntpd[1953]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:30:36 volumio systemd[1]: Started Network Time Service. Apr 14 16:30:36 volumio ntpd[1959]: proto: precision = 0.113 usec (-23) Apr 14 16:30:36 volumio ntpd[1959]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:30:36 volumio ntpd[1959]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:30:36 volumio ntpd[1959]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:30:36 volumio ntpd[1959]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:30:36 volumio ntpd[1959]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:30:36 volumio ntpd[1959]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:30:36 volumio ntpd[1959]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:30:36 volumio ntpd[1959]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:30:36 volumio ntpd[1959]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:30:36 volumio ntpd[1959]: Listening on routing socket on fd #22 for interface updates Apr 14 16:30:36 volumio ntpd[1959]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:36 volumio ntpd[1959]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:36 volumio ntpd[1959]: ntpd exiting on signal 15 (Terminated) Apr 14 16:30:36 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:30:36 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:30:36 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:30:36 volumio systemd[1]: Starting Network Time Service... Apr 14 16:30:36 volumio ntpd[1993]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:30:36 volumio ntpd[1993]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:30:36 volumio systemd[1]: Started Network Time Service. Apr 14 16:30:36 volumio ntpd[1999]: proto: precision = 0.081 usec (-23) Apr 14 16:30:36 volumio ntpd[1999]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:30:36 volumio ntpd[1999]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:30:36 volumio ntpd[1999]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:30:36 volumio ntpd[1999]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:30:36 volumio ntpd[1999]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:30:36 volumio ntpd[1999]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:30:36 volumio ntpd[1999]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:30:36 volumio ntpd[1999]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:30:36 volumio ntpd[1999]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:30:36 volumio ntpd[1999]: Listening on routing socket on fd #22 for interface updates Apr 14 16:30:36 volumio ntpd[1999]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:36 volumio ntpd[1999]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:30:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 14 16:30:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Apr 14 16:30:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 14 16:30:37 volumio systemd[1]: Started go-librespot Daemon. Apr 14 16:30:37 volumio go-librespot[2001]: Librespot-go daemon starting... Apr 14 16:30:37 volumio go-librespot[2001]: time="2025-04-14T16:30:37+02:00" level=info msg="generated new device id: 8d60bde7a63b3390affe1fbd4c79a824bda6313a" Apr 14 16:30:37 volumio go-librespot[2001]: time="2025-04-14T16:30:37+02:00" level=debug msg="stored credentials found for 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:30:39 volumio volumio-time-update[776]: volumio-time-update-util: Date not found in response Apr 14 16:30:39 volumio volumio-time-update[776]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 16:30:44 volumio volumio-time-update[776]: volumio-time-update-util: Fetching time from Volumio... Apr 14 16:30:53 volumio dhcpcd[1445]: eth0: failed to renew DHCP, rebinding Apr 14 16:30:53 volumio dhcpcd[1409]: eth0: failed to renew DHCP, rebinding Apr 14 16:30:56 volumio dhcpcd[1445]: eth0: DHCP lease expired Apr 14 16:30:56 volumio avahi-daemon[774]: Withdrawing address record for 192.168.178.17 on eth0. Apr 14 16:30:56 volumio avahi-daemon[774]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.178.17. Apr 14 16:30:56 volumio avahi-daemon[774]: Interface eth0.IPv4 no longer relevant for mDNS. Apr 14 16:30:56 volumio volumio[1056]: info: Discovery: A device disappeared from network Apr 14 16:30:56 volumio volumio[1056]: info: Discovery: Device volumio disappeared from network Apr 14 16:30:56 volumio dhcpcd[1409]: eth0: pid -850314115 deleted IP address 192.168.178.17/24 Apr 14 16:30:56 volumio dhcpcd[1409]: eth0: deleting route to 192.168.178.0/24 Apr 14 16:30:56 volumio dhcpcd[1409]: eth0: deleting default route via 192.168.178.1 Apr 14 16:30:56 volumio dhcpcd[1445]: wlan0: adding default route Apr 14 16:30:56 volumio dhcpcd[1445]: eth0: deleting route to 192.168.178.0/24 Apr 14 16:30:56 volumio dhcpcd[1445]: eth0: deleting default route via 192.168.178.1 Apr 14 16:30:56 volumio dnsmasq[1086]: reading /etc/resolv.conf Apr 14 16:30:56 volumio dnsmasq[1086]: using nameserver 208.67.222.222#53 Apr 14 16:30:56 volumio dnsmasq[1086]: using nameserver 208.67.220.220#53 Apr 14 16:30:56 volumio dhcpcd[1409]: eth0: rebinding lease of 192.168.178.17 Apr 14 16:30:56 volumio dnsmasq[1086]: no servers found in /etc/resolv.conf, will retry Apr 14 16:30:56 volumio dhcpcd[1445]: eth0: soliciting a DHCP lease Apr 14 16:30:56 volumio dhcpcd[1409]: eth0: probing address 192.168.178.17/24 Apr 14 16:30:56 volumio dhcpcd[1445]: eth0: offered 192.168.178.17 from 192.168.178.1 Apr 14 16:30:56 volumio dhcpcd[1445]: eth0: probing address 192.168.178.17/24 Apr 14 16:30:57 volumio volumio[1056]: info: Discovery: adding e96b2210-1ef5-4f4b-8dfe-c3b90fcd7b55 Apr 14 16:30:57 volumio volumio[1056]: info: Discovery: Found device Volumio Apr 14 16:30:57 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 14 16:30:57 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 14 16:30:57 volumio go-librespot[2001]: time="2025-04-14T16:30:57+02:00" level=debug msg="new websocket client" Apr 14 16:30:57 volumio volumio[1056]: info: Connection to go-librespot Websocket established Apr 14 16:30:57 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 16:30:57 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 14 16:30:57 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 14 16:30:57 volumio ntpd[1999]: Deleting interface #3 eth0, 192.168.178.17#123, interface stats: received=0, sent=0, dropped=0, active_time=21 secs Apr 14 16:30:58 volumio volumio[1056]: info: Volumio Network Manager: Network status updated: 0 Apr 14 16:30:59 volumio go-librespot[2001]: time="2025-04-14T16:30:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 14 16:30:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 16:30:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 16:30:59 volumio volumio[1056]: info: Connection to go-librespot Websocket closed Apr 14 16:31:00 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 14 16:31:00 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 14 16:31:00 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 14 16:31:00 volumio volumio[1056]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Apr 14 16:31:00 volumio volumio[1056]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 16:31:00 volumio volumio[1056]: SPOTIFY: VOLUMIO VOLUME 51 Apr 14 16:31:00 volumio volumio[1056]: info: Aligning Spotify Volume to Volumio Volume Apr 14 16:31:00 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 14 16:31:00 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 14 16:31:00 volumio volumio[1056]: info: Setting Spotify Volume from Volumio: 51 Apr 14 16:31:00 volumio volumio[1056]: info: Getting Spotify volume Apr 14 16:31:00 volumio volumio[1056]: (node:1056) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 16:31:00 volumio volumio[1056]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Apr 14 16:31:00 volumio volumio[1056]: (node:1056) 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: 3) Apr 14 16:31:00 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 14 16:31:00 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 14 16:31:00 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 14 16:31:00 volumio volumio[1056]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Apr 14 16:31:01 volumio volumio[1056]: SPOTIFY: SETTING SPOTIFY VOLUME 51 Apr 14 16:31:01 volumio volumio[1056]: info: Sending Spotify command with payload to local API: /player/volume Apr 14 16:31:01 volumio volumio[1056]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 16:31:01 volumio dhcpcd[1445]: eth0: leased 192.168.178.17 for 20 seconds Apr 14 16:31:01 volumio dhcpcd[1445]: eth0: adding route to 192.168.178.0/24 Apr 14 16:31:01 volumio avahi-daemon[774]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.17. Apr 14 16:31:01 volumio dhcpcd[1445]: eth0: adding default route via 192.168.178.1 Apr 14 16:31:01 volumio avahi-daemon[774]: New relevant interface eth0.IPv4 for mDNS. Apr 14 16:31:01 volumio dhcpcd[1445]: wlan0: deleting default route Apr 14 16:31:01 volumio avahi-daemon[774]: Registering new address record for 192.168.178.17 on eth0.IPv4. Apr 14 16:31:01 volumio dnsmasq[1086]: reading /etc/resolv.conf Apr 14 16:31:01 volumio dnsmasq[1086]: using nameserver 192.168.178.1#53 Apr 14 16:31:01 volumio dnsmasq[1086]: using nameserver 208.67.222.222#53 Apr 14 16:31:01 volumio dnsmasq[1086]: using nameserver 208.67.220.220#53 Apr 14 16:31:01 volumio ntpd[1999]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:01 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:01 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:01 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:01 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:01 volumio ntpd[2148]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:01 volumio ntpd[2148]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:01 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:01 volumio ntpd[2154]: proto: precision = 0.075 usec (-24) Apr 14 16:31:01 volumio ntpd[2154]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:01 volumio ntpd[2154]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:01 volumio ntpd[2154]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:01 volumio ntpd[2154]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:01 volumio ntpd[2154]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:01 volumio ntpd[2154]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:01 volumio ntpd[2154]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:01 volumio ntpd[2154]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:01 volumio ntpd[2154]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:01 volumio ntpd[2154]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:01 volumio ntpd[2154]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:01 volumio ntpd[2154]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:01 volumio dhcpcd[1409]: eth0: leased 192.168.178.17 for 20 seconds Apr 14 16:31:01 volumio dhcpcd[1409]: eth0: adding route to 192.168.178.0/24 Apr 14 16:31:01 volumio dhcpcd[1409]: eth0: adding default route via 192.168.178.1 Apr 14 16:31:01 volumio ntpd[2154]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:01 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:01 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:01 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:01 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:01 volumio ntpd[2189]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:01 volumio ntpd[2189]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:01 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:01 volumio ntpd[2195]: proto: precision = 0.063 usec (-24) Apr 14 16:31:01 volumio ntpd[2195]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:01 volumio ntpd[2195]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:01 volumio ntpd[2195]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:01 volumio ntpd[2195]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:01 volumio ntpd[2195]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:01 volumio ntpd[2195]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:01 volumio ntpd[2195]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:01 volumio ntpd[2195]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:01 volumio ntpd[2195]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:01 volumio ntpd[2195]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:01 volumio ntpd[2195]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:01 volumio ntpd[2195]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:02 volumio volumio[1056]: info: Initializing connection to go-librespot Websocket Apr 14 16:31:02 volumio volumio[1056]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 16:31:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 14 16:31:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Apr 14 16:31:02 volumio systemd[1]: Stopped go-librespot Daemon. Apr 14 16:31:02 volumio systemd[1]: Started go-librespot Daemon. Apr 14 16:31:02 volumio go-librespot[2197]: Librespot-go daemon starting... Apr 14 16:31:02 volumio go-librespot[2197]: time="2025-04-14T16:31:02+02:00" level=info msg="generated new device id: bb0af22da896afa1563dd8d6517dad0b2dc28191" Apr 14 16:31:02 volumio go-librespot[2197]: time="2025-04-14T16:31:02+02:00" level=debug msg="stored credentials found for 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:31:05 volumio volumio[1056]: info: Initializing connection to go-librespot Websocket Apr 14 16:31:07 volumio volumio-time-update[776]: volumio-time-update-util: Date not found in response Apr 14 16:31:07 volumio volumio-time-update[776]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 16:31:08 volumio volumio[1056]: info: Volumio Network Manager: Network status updated: 1 Apr 14 16:31:11 volumio ntpd[2195]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:11 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:11 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:11 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:11 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:11 volumio ntpd[2251]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:11 volumio ntpd[2251]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:11 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:11 volumio ntpd[2257]: proto: precision = 0.093 usec (-23) Apr 14 16:31:11 volumio ntpd[2257]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:11 volumio ntpd[2257]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:11 volumio ntpd[2257]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:11 volumio ntpd[2257]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:11 volumio ntpd[2257]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:11 volumio ntpd[2257]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:11 volumio ntpd[2257]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:11 volumio ntpd[2257]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:11 volumio ntpd[2257]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:11 volumio ntpd[2257]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:11 volumio ntpd[2257]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:11 volumio ntpd[2257]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:11 volumio ntpd[2257]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:11 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:11 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:11 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:11 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:11 volumio ntpd[2291]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:11 volumio ntpd[2291]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:11 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:11 volumio ntpd[2297]: proto: precision = 0.106 usec (-23) Apr 14 16:31:11 volumio ntpd[2297]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:11 volumio ntpd[2297]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:11 volumio ntpd[2297]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:11 volumio ntpd[2297]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:11 volumio ntpd[2297]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:11 volumio ntpd[2297]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:11 volumio ntpd[2297]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:11 volumio ntpd[2297]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:11 volumio ntpd[2297]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:11 volumio ntpd[2297]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:11 volumio ntpd[2297]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:11 volumio ntpd[2297]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:12 volumio volumio-time-update[776]: volumio-time-update-util: Fetching time from Volumio... Apr 14 16:31:21 volumio ntpd[2297]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:21 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:21 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:21 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:21 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:21 volumio ntpd[2352]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:21 volumio ntpd[2352]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:21 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:21 volumio ntpd[2358]: proto: precision = 0.098 usec (-23) Apr 14 16:31:21 volumio ntpd[2358]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:21 volumio ntpd[2358]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:21 volumio ntpd[2358]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:21 volumio ntpd[2358]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:21 volumio ntpd[2358]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:21 volumio ntpd[2358]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:21 volumio ntpd[2358]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:21 volumio ntpd[2358]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:21 volumio ntpd[2358]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:21 volumio ntpd[2358]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:21 volumio ntpd[2358]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:21 volumio ntpd[2358]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:21 volumio ntpd[2358]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:21 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:21 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:21 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:21 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:21 volumio ntpd[2392]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:21 volumio ntpd[2392]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:21 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:21 volumio ntpd[2398]: proto: precision = 0.062 usec (-24) Apr 14 16:31:21 volumio ntpd[2398]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:21 volumio ntpd[2398]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:21 volumio ntpd[2398]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:21 volumio ntpd[2398]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:21 volumio ntpd[2398]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:21 volumio ntpd[2398]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:21 volumio ntpd[2398]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:21 volumio ntpd[2398]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:21 volumio ntpd[2398]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:21 volumio ntpd[2398]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:21 volumio ntpd[2398]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:21 volumio ntpd[2398]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:30 volumio go-librespot[2197]: time="2025-04-14T16:31:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 14 16:31:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 16:31:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 16:31:31 volumio ntpd[2398]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:31 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:31 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:31 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:31 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:31 volumio ntpd[2446]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:31 volumio ntpd[2446]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:31 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:31 volumio ntpd[2452]: proto: precision = 0.064 usec (-24) Apr 14 16:31:31 volumio ntpd[2452]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:31 volumio ntpd[2452]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:31 volumio ntpd[2452]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:31 volumio ntpd[2452]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:31 volumio ntpd[2452]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:31 volumio ntpd[2452]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:31 volumio ntpd[2452]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:31 volumio ntpd[2452]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:31 volumio ntpd[2452]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:31 volumio ntpd[2452]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:31 volumio ntpd[2452]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:31 volumio ntpd[2452]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:32 volumio ntpd[2452]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:32 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:32 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:32 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:32 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:32 volumio ntpd[2486]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:32 volumio ntpd[2486]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:32 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:32 volumio ntpd[2492]: proto: precision = 0.063 usec (-24) Apr 14 16:31:32 volumio ntpd[2492]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:32 volumio ntpd[2492]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:32 volumio ntpd[2492]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:32 volumio ntpd[2492]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:32 volumio ntpd[2492]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:32 volumio ntpd[2492]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:32 volumio ntpd[2492]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:32 volumio ntpd[2492]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:32 volumio ntpd[2492]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:32 volumio ntpd[2492]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:32 volumio ntpd[2492]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:32 volumio ntpd[2492]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 14 16:31:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Apr 14 16:31:33 volumio systemd[1]: Stopped go-librespot Daemon. Apr 14 16:31:33 volumio systemd[1]: Started go-librespot Daemon. Apr 14 16:31:33 volumio go-librespot[2497]: Librespot-go daemon starting... Apr 14 16:31:33 volumio go-librespot[2497]: time="2025-04-14T16:31:33+02:00" level=info msg="generated new device id: 044233587312b64e62746b7201a63ec1852ee464" Apr 14 16:31:33 volumio go-librespot[2497]: time="2025-04-14T16:31:33+02:00" level=debug msg="stored credentials found for 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:31:40 volumio volumio-time-update[776]: volumio-time-update-util: Date not found in response Apr 14 16:31:40 volumio volumio-time-update[776]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 16:31:41 volumio dnsmasq[1086]: reading /etc/resolv.conf Apr 14 16:31:41 volumio dnsmasq[1086]: using nameserver 62.179.104.196#53 Apr 14 16:31:41 volumio dnsmasq[1086]: using nameserver 213.46.228.196#53 Apr 14 16:31:41 volumio dnsmasq[1086]: using nameserver 208.67.222.222#53 Apr 14 16:31:41 volumio dnsmasq[1086]: using nameserver 208.67.220.220#53 Apr 14 16:31:41 volumio ntpd[2492]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:41 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:41 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:41 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:41 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:41 volumio ntpd[2554]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:41 volumio ntpd[2554]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:41 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:41 volumio ntpd[2560]: proto: precision = 0.095 usec (-23) Apr 14 16:31:41 volumio ntpd[2560]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:41 volumio ntpd[2560]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:41 volumio ntpd[2560]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:41 volumio ntpd[2560]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:41 volumio ntpd[2560]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:41 volumio ntpd[2560]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:41 volumio ntpd[2560]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:41 volumio ntpd[2560]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:41 volumio ntpd[2560]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:41 volumio ntpd[2560]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:41 volumio ntpd[2560]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:41 volumio ntpd[2560]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:42 volumio ntpd[2560]: ntpd exiting on signal 15 (Terminated) Apr 14 16:31:42 volumio systemd[1]: Stopping Network Time Service... Apr 14 16:31:42 volumio systemd[1]: ntp.service: Succeeded. Apr 14 16:31:42 volumio systemd[1]: Stopped Network Time Service. Apr 14 16:31:42 volumio systemd[1]: Starting Network Time Service... Apr 14 16:31:42 volumio ntpd[2594]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 16:31:42 volumio ntpd[2594]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 14 16:31:42 volumio systemd[1]: Started Network Time Service. Apr 14 16:31:42 volumio ntpd[2600]: proto: precision = 0.073 usec (-24) Apr 14 16:31:42 volumio ntpd[2600]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 16:31:42 volumio ntpd[2600]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 16:31:42 volumio ntpd[2600]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 839 days ago Apr 14 16:31:42 volumio ntpd[2600]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 16:31:42 volumio ntpd[2600]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 16:31:42 volumio ntpd[2600]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 16:31:42 volumio ntpd[2600]: Listen normally on 3 eth0 192.168.178.17:123 Apr 14 16:31:42 volumio ntpd[2600]: Listen normally on 4 wlan0 192.168.211.1:123 Apr 14 16:31:42 volumio ntpd[2600]: Listen normally on 5 wlan0 169.254.252.231:123 Apr 14 16:31:42 volumio ntpd[2600]: Listening on routing socket on fd #22 for interface updates Apr 14 16:31:42 volumio ntpd[2600]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:42 volumio ntpd[2600]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 16:31:45 volumio volumio-time-update[776]: volumio-time-update-util: Fetching time from Volumio... Apr 14 16:31:46 volumio go-librespot[2497]: time="2025-04-14T16:31:46+02:00" level=debug msg="new websocket client" Apr 14 16:31:46 volumio volumio[1056]: info: Connection to go-librespot Websocket established Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="zeroconf server listening on port 35801" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="obtained new client token: AADF9Vu4gKDNdBcKHhykyIy957GemetPTp1ji/B6kG44WOskrgZuz8el6Ulax2QZMOH9hD0wiCJiPoNsN+n+hCJ9B6MADq0Vv8XQ64x/8v39YqfqnNGoEo9cO7DQywxZYvcia3BncD8Smm3/fjxMyIslNjk+Mde7RQB+CxAJX1wkofuYL0tdEHuTmOjjb22TpulC/c9RiZBVoZSBzg5pOj7yiIn9uR/UEXLao5oI/aXLF2AVlLR6M3JZmGd9" Apr 14 16:31:48 volumio ntpd[2600]: Soliciting pool server 178.215.228.24 Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 14 16:31:48 volumio ntpd[2600]: Soliciting pool server 185.51.192.63 Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="completed keyexchange" Apr 14 16:31:48 volumio ntpd[2600]: Soliciting pool server 193.123.56.220 Apr 14 16:31:48 volumio ntpd[2600]: Soliciting pool server 84.84.17.253 Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 16:31:48 volumio volumio[1056]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 16:31:48 volumio volumio[1056]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 16:31:48 volumio volumio[1056]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 16:31:48 volumio volumio[1056]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 16:31:48 volumio volumio[1056]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 16:31:48 volumio volumio[1056]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 16:31:48 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 16:31:48 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 16:31:48 volumio volumio[1056]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 16:31:48 volumio volumio[1056]: info: MyVolumio login type: Token Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 16:31:48 volumio volumio[1056]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="completed challenge" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="authenticated as 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="authenticated as 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="dealer connection opened" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="initializing zeroconf session, username: 312gsxudwikphlm4khzezxb7nspu" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="autoplay enabled: false" Apr 14 16:31:48 volumio go-librespot[2497]: time="2025-04-14T16:31:48+02:00" level=debug msg="received connection id: NGQ1MWJjODQtMjE4Yy00MTkxLTlhNTctZDNiZTVlNmVhYTMxK2RlYWxlcit0Y3A6Ly8wYWNhNTk3OC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOEFGNDFBQkU5QzdFREVFNTJCMDQxNEQ2NjY5N0MwODZFRUIyQUZEQ0I4OTJENDE1NzAzNkZCQjgwNzdCMUI0Rg==" Apr 14 16:31:49 volumio volumio[1056]: info: Starting Streaming Service Transparent Proxy Apr 14 16:31:49 volumio volumio[1056]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 16:31:49 volumio volumio[1056]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 16:31:49 volumio volumio[1056]: info: Streaming services startup Apr 14 16:31:49 volumio volumio[1056]: info: Starting Streaming Daemon Apr 14 16:31:49 volumio sudo[2628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 16:31:49 volumio sudo[2628]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 16:31:49 volumio volumio[1056]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 16:31:49 volumio sudo[2628]: pam_unix(sudo:session): session closed for user root Apr 14 16:31:49 volumio go-librespot[2497]: time="2025-04-14T16:31:49+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 14 16:31:49 volumio volumio[1056]: error: Cannot start Volumio Streaming Daemon Apr 14 16:31:49 volumio volumio[1056]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 16:31:49 volumio volumio[1056]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 16:31:49 volumio ntpd[2600]: Soliciting pool server 193.123.38.172 Apr 14 16:31:49 volumio ntpd[2600]: Soliciting pool server 178.239.19.60 Apr 14 16:31:49 volumio ntpd[2600]: Soliciting pool server 178.239.19.58 Apr 14 16:31:49 volumio ntpd[2600]: Soliciting pool server 162.159.200.123 Apr 14 16:31:49 volumio volumio[1056]: STREAMING PROXY: Starting server on port 3245 Apr 14 16:31:49 volumio volumio[1056]: Node JS runtime: 14 Apr 14 16:31:49 volumio volumio[1056]: error: MyVolumio Custom Token format not valid, refreshing it Apr 14 16:31:49 volumio volumio[1056]: info: Discovery: this is already registered, e96b2210-1ef5-4f4b-8dfe-c3b90fcd7b55 Apr 14 16:31:49 volumio volumio[1056]: info: Discovery: Found device Volumio Apr 14 16:31:49 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 14 16:31:49 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 14 16:31:49 volumio volumio[1056]: info: Getting Spotify volume Apr 14 16:31:49 volumio volumio[1056]: info: Spotify volume: 100 Apr 14 16:31:49 volumio volumio[1056]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 14 16:31:49 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 14 16:31:49 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 14 16:31:49 volumio volumio[1056]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Apr 14 16:31:49 volumio volumio[1056]: SPOTIFY: SPOTIFY VOLUME 100 Apr 14 16:31:49 volumio volumio[1056]: SPOTIFY: VOLUMIO VOLUME 51 Apr 14 16:31:49 volumio volumio[1056]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 14 16:31:49 volumio volumio[1056]: info: Setting Spotify Volume from Volumio: 51 Apr 14 16:31:49 volumio volumio[1056]: info: MyVolumio login type: Token Apr 14 16:31:50 volumio ntpd[2600]: Soliciting pool server 178.239.19.57 Apr 14 16:31:50 volumio ntpd[2600]: Soliciting pool server 178.239.19.56 Apr 14 16:31:50 volumio volumio[1056]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 16:31:50 volumio volumio[1056]: info: MyVolumio token set successfully Apr 14 16:31:50 volumio volumio[1056]: info: MYVOLUMIO: Adding device Apr 14 16:31:50 volumio volumio[1056]: info: MYVOLUMIO: Evaluating Server Apr 14 16:31:50 volumio volumio[1056]: info: MyVolumio status changed Apr 14 16:31:50 volumio volumio[1056]: info: Streaming services startup Apr 14 16:31:50 volumio volumio[1056]: info: Starting Streaming Daemon Apr 14 16:31:50 volumio volumio[1056]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 16:31:50 volumio volumio[1056]: info: Removing audio output: Apr 14 16:31:50 volumio volumio[1056]: info: Stoppping Tunnel 1 Apr 14 16:31:50 volumio sudo[2653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 16:31:50 volumio sudo[2653]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 16:31:50 volumio sudo[2653]: pam_unix(sudo:session): session closed for user root Apr 14 16:31:50 volumio sudo[2656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 16:31:50 volumio sudo[2656]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 16:31:50 volumio volumio[1056]: error: Cannot start Volumio Streaming Daemon Apr 14 16:31:50 volumio volumio[1056]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 16:31:50 volumio volumio[1056]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 16:31:50 volumio sudo[2656]: pam_unix(sudo:session): session closed for user root Apr 14 16:31:50 volumio volumio[1056]: info: Remote SSH Stopped Apr 14 16:31:50 volumio volumio-time-update[776]: volumio-time-update-util: Setting system time to: 2025-04-14 16:31:50 Apr 14 16:31:50 volumio sudo[2659]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-04-14 16:31:50 Apr 14 16:31:50 volumio sudo[2659]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 16:31:50 volumio dbus-daemon[766]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.15' (uid=0 pid=2660 comm="timedatectl set-time 2025-04-14 16:31:50 ") Apr 14 16:31:51 volumio systemd[1]: Starting Time & Date Service... Apr 14 16:31:51 volumio dbus-daemon[766]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 14 16:31:51 volumio systemd[1]: Started Time & Date Service. Apr 14 16:31:50 volumio systemd-timedated[2661]: Changed local time to Mon Apr 14 16:31:50 2025 Apr 14 16:31:50 volumio sudo[2659]: pam_unix(sudo:session): session closed for user root Apr 14 16:31:50 volumio volumio-time-update[776]: volumio-time-update-util: System time updated successfully. Apr 14 16:31:50 volumio systemd[1]: Started Volumio Time Update Utility. Apr 14 16:31:50 volumio systemd[1]: Reached target Multi-User System. Apr 14 16:31:50 volumio systemd[1]: Reached target Graphical Interface. Apr 14 16:31:50 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 14 16:31:50 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 14 16:31:50 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 14 16:31:50 volumio systemd[1]: Startup finished in 8.586s (firmware) + 2.408s (loader) + 6.676s (kernel) + 3min 1.130s (userspace) = 3min 18.801s. Apr 14 16:31:50 volumio volumio[1056]: error: Failed to ping endpoint as1.myvolumio.org : unknown error Apr 14 16:31:50 volumio volumio[1056]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 16:31:50 volumio volumio[1056]: Error: Unable to resolve or reject the same promise twice Apr 14 16:31:50 volumio volumio[1056]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 14 16:31:50 volumio volumio[1056]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Apr 14 16:31:50 volumio volumio[1056]: at Socket.emit (events.js:412:35) Apr 14 16:31:50 volumio volumio[1056]: at endReadableNT (internal/streams/readable.js:1333:12) Apr 14 16:31:50 volumio volumio[1056]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Apr 14 16:31:50 volumio volumio[1056]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 16:31:50 volumio sudo[2673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-14 16:30 Apr 14 16:31:50 volumio sudo[2673]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:27:48 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4bc1ecb08f34ad14b420d6678a2aef1b"