Jul 05 01:25:13 volumio ntpd[795]: CLOCK: time stepped by 388886.569508 Jul 05 01:25:13 volumio ntpd[795]: CLOCK: time changed from 2025-06-30 to 2025-07-05 Jul 05 01:25:13 volumio ntpd[795]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jul 05 01:25:13 volumio systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Jul 05 01:25:13 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jul 05 01:25:13 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jul 05 01:25:13 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jul 05 01:25:14 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jul 05 01:25:14 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jul 05 01:25:14 volumio volumio[2030]: info: CoreCommandRouter::volumioGetState Jul 05 01:25:14 volumio volumio[2030]: info: CorePlayQueue::getTrack 0 Jul 05 01:25:14 volumio volumio[2030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 05 01:25:14 volumio volumio[2030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 05 01:25:14 volumio volumio[2030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 05 01:25:14 volumio dhcpcd[685]: wlan0: leased 192.168.1.15 for infinity Jul 05 01:25:14 volumio avahi-daemon[1332]: Registering new address record for 192.168.1.15 on wlan0.IPv4. Jul 05 01:25:14 volumio dhcpcd[685]: wlan0: adding route to 192.168.1.0/24 Jul 05 01:25:14 volumio dhcpcd[685]: wlan0: adding default route via 192.168.1.1 Jul 05 01:25:14 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Jul 05 01:25:14 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Jul 05 01:25:14 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Jul 05 01:25:15 volumio avahi-daemon[1332]: Withdrawing address record for 169.254.188.135 on wlan0. Jul 05 01:25:15 volumio avahi-daemon[1332]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.188.135. Jul 05 01:25:15 volumio dhcpcd[685]: wlan0: deleting route to 169.254.0.0/16 Jul 05 01:25:15 volumio avahi-daemon[1332]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.15. Jul 05 01:25:15 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Jul 05 01:25:15 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Jul 05 01:25:15 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Jul 05 01:25:15 volumio systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Jul 05 01:25:15 volumio systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Jul 05 01:25:15 volumio systemd[1]: apt-daily-upgrade.service: Consumed 1.066s CPU time. Jul 05 01:25:16 volumio go-librespot[2258]: time="2025-07-05T01:25:16+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 35.186.224.24:443: i/o timeout" Jul 05 01:25:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 01:25:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 01:25:16 volumio ntpd[795]: IO: Listen normally on 10 wlan0 192.168.1.15:123 Jul 05 01:25:16 volumio ntpd[795]: IO: Deleting interface #9 wlan0, 169.254.188.135#123, interface stats: received=0, sent=0, dropped=0, active_time=9 secs Jul 05 01:25:16 volumio ntpd[795]: IO: new interface(s) found: waking up resolver Jul 05 01:25:16 volumio ntpd[795]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 05 01:25:16 volumio ntpd[795]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jul 05 01:25:16 volumio ntpd[795]: DNS: Pool skipping: 89.46.74.148 Jul 05 01:25:16 volumio ntpd[795]: DNS: Pool skipping: 81.56.230.156 Jul 05 01:25:16 volumio ntpd[795]: DNS: Pool skipping: 212.45.144.3 Jul 05 01:25:16 volumio ntpd[795]: DNS: Pool skipping: 185.157.229.254 Jul 05 01:25:16 volumio ntpd[795]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jul 05 01:25:17 volumio nmbd[930]: [2025/07/05 01:25:17.449323, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jul 05 01:25:17 volumio nmbd[930]: Packet send failed to 192.168.0.255(138) ERRNO=Network is unreachable Jul 05 01:25:17 volumio volumio[2030]: info: Discovery: A device disappeared from network Jul 05 01:25:17 volumio volumio[2030]: info: Discovery: Device volumio disappeared from network Jul 05 01:25:17 volumio ntpd[795]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 05 01:25:17 volumio ntpd[795]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 193.204.114.233 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 193.204.114.105 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 212.45.144.206 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 93.94.88.51 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 2606:4700:f1::1 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 2a00:6d41:200:2::15 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 2a07:7e81:7140:0:7a9a:18ff:fec7:9d36 Jul 05 01:25:17 volumio ntpd[795]: DNS: Pool skipping: 2a00:6d41:10:1194::3 Jul 05 01:25:17 volumio ntpd[795]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jul 05 01:25:17 volumio volumio-remote-updater[607]: Test mode enabled Jul 05 01:25:17 volumio volumio-remote-updater[607]: Alpha mode disabled Jul 05 01:25:17 volumio volumio-remote-updater[607]: Alpha legacy test mode disabled Jul 05 01:25:17 volumio volumio[2030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jul 05 01:25:17 volumio volumio[2030]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 01:25:17 volumio volumio[2030]: Error: socket hang up Jul 05 01:25:17 volumio volumio[2030]: at connResetException (node:internal/errors:720:14) Jul 05 01:25:17 volumio volumio[2030]: at Socket.socketOnEnd (node:_http_client:519:23) Jul 05 01:25:17 volumio volumio[2030]: at Socket.emit (node:events:526:35) Jul 05 01:25:17 volumio volumio[2030]: at endReadableNT (node:internal/streams/readable:1376:12) Jul 05 01:25:17 volumio volumio[2030]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jul 05 01:25:17 volumio volumio[2030]: code: 'ECONNRESET', Jul 05 01:25:17 volumio volumio[2030]: response: undefined Jul 05 01:25:17 volumio volumio[2030]: } Jul 05 01:25:17 volumio volumio[2030]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 01:25:18 volumio ntpd[795]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 05 01:25:18 volumio ntpd[795]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jul 05 01:25:18 volumio ntpd[795]: DNS: Pool skipping: 80.211.238.32 Jul 05 01:25:18 volumio ntpd[795]: DNS: Pool skipping: 212.6.50.243 Jul 05 01:25:18 volumio ntpd[795]: DNS: Pool skipping: 89.46.74.148 Jul 05 01:25:18 volumio ntpd[795]: DNS: Pool skipping: 185.157.229.254 Jul 05 01:25:18 volumio ntpd[795]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jul 05 01:25:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 05 01:25:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 05 01:25:19 volumio ntpd[795]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jul 05 01:25:19 volumio ntpd[795]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jul 05 01:25:19 volumio ntpd[795]: DNS: Pool skipping: 212.6.50.243 Jul 05 01:25:19 volumio ntpd[795]: DNS: Pool skipping: 31.207.113.74 Jul 05 01:25:19 volumio ntpd[795]: DNS: Pool skipping: 93.44.243.48 Jul 05 01:25:19 volumio ntpd[795]: DNS: Pool skipping: 85.199.214.99 Jul 05 01:25:19 volumio ntpd[795]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jul 05 01:25:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 05 01:25:19 volumio go-librespot[2490]: go-librespot daemon starting... Jul 05 01:25:19 volumio go-librespot[2492]: time="2025-07-05T01:25:19+02:00" level=info msg="running go-librespot 0.2.0" Jul 05 01:25:19 volumio go-librespot[2492]: time="2025-07-05T01:25:19+02:00" level=debug msg="app state loaded" Jul 05 01:25:19 volumio go-librespot[2492]: time="2025-07-05T01:25:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" 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]" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" 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]" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=info msg="zeroconf server listening on port 45985" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=debug msg="obtained new client token: AADURJzNJKtJ3+Fhkdc8rDvVxWycLGWER7J/KCQpTmTLtdEBhLl28dV3f36kXS3LjXoauy+LDMOdJ/CZWPZJ5aTQe10MTIpOiwGUkjEo/pvryA2lZHJjILF52xAxSeV9NCh8Mva/YLBquj0x6kOhFq27afUnU0BWJn27NN1UBDA+PCSU3qv0PmDoaP2TGYFbl8N9DlD0mN0IB2SI7UVm/oFIUNTt4nOfUUxDsw0Ao6CNCfcShjzycOKoJA==" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=debug msg="completed keyexchange" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=debug msg="completed challenge" Jul 05 01:25:20 volumio go-librespot[2492]: time="2025-07-05T01:25:20+02:00" level=info msg="authenticated AP as 5wrd3r0dueuhg7ebvjp9tq04l" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=info msg="authenticated Login5 as 5wrd3r0dueuhg7ebvjp9tq04l" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="initializing zeroconf session, username: 5wrd3r0dueuhg7ebvjp9tq04l" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="dealer connection opened" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=trace msg="starting accesspoint recv loop" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=trace msg="starting dealer recv loop" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=trace msg="received accesspoint ping" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=debug msg="received connection id: OTk3NjZjNzgtMzFlMy00MGJkLWIxOGQtMzViMThhODZjNTY2K2RlYWxlcit0Y3A6Ly8wYWIxNTBkZi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQjcyREJBNUQ3NTcyMkM0RUE3OThEMTc1RUM0MkVBODBDREMwQUUwMTgyNDg4OTgyOUM5QTAwNzFCOEUyN0Q1QQ==" Jul 05 01:25:21 volumio go-librespot[2492]: time="2025-07-05T01:25:21+02:00" level=trace msg="received accesspoint pong ack" Jul 05 01:25:21 volumio sudo[2517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-05 01:24' Jul 05 01:25:21 volumio sudo[2517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f9454895cc8e2f1971c705a815a7226e021e37d7" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1fc282af1865fae9b40239cedf2cc17c112eef0d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 28 16:48:46 UTC 2025" VOLUMIO_VERSION="4.014" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="1b557e4869cd2eea14f4113140ecea1c"