-- Logs begin at Tue 2025-09-02 15:59:32 BST, end at Thu 2025-09-04 12:13:48 BST. -- Sep 04 12:12:01 volumio tailscaled[20949]: health(warnable=not-in-map-poll): error: Unable to connect to the Tailscale coordination server to synchronize the state of your tailnet. Peer reachability might degrade over time. Sep 04 12:12:01 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:01 volumio tailscaled[20949]: bootstrapDNS("derp12e.tailscale.com", "209.177.158.15") for "log.tailscale.com" error: Get "https://derp12e.tailscale.com/bootstrap-dns?q=log.tailscale.com": context deadline exceeded Sep 04 12:12:01 volumio tailscaled[20949]: trying bootstrapDNS("derp13b.tailscale.com", "2607:f740:16::640") for "log.tailscale.com" ... Sep 04 12:12:01 volumio tailscaled[20949]: bootstrapDNS("derp13b.tailscale.com", "2607:f740:16::640") for "log.tailscale.com" error: Get "https://derp13b.tailscale.com/bootstrap-dns?q=log.tailscale.com": dial tcp [2607:f740:16::640]:443: connect: cannot assign requested address Sep 04 12:12:01 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:02 volumio tailscaled[20949]: control: lite map update error after 16.804s: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:12:04 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:04 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:12:05 volumio tailscaled[20949]: Received error: PollNetMap: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:12:06 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): context deadline exceeded Sep 04 12:12:06 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:09 volumio ntpd[812]: Soliciting pool server 10.0.0.1 Sep 04 12:12:09 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:12:09 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:12:09 volumio tailscaled[20949]: control: controlhttp: context aborted dialing Sep 04 12:12:09 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:12:11 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:12 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:16 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:16 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:12:16 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): dial tcp6 [2a00:dd80:3c::3d5]:443: connect: cannot assign requested address Sep 04 12:12:16 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:19 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:12:19 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:12:21 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:21 volumio tailscaled[20949]: control: controlhttp: failed dialing using DialPlan, falling back to DNS; errs=multiple errors: Sep 04 12:12:21 volumio tailscaled[20949]: connection attempts aborted by context: context deadline exceeded Sep 04 12:12:22 volumio ntpd[812]: Soliciting pool server 10.0.0.1 Sep 04 12:12:25 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): dial tcp6 [2a00:dd80:3c::3d5]:443: connect: cannot assign requested address Sep 04 12:12:25 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:26 volumio tailscaled[20949]: control: lite map update error after 18.024s: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:12:26 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:28 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:12:28 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:12:30 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:12:30 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:32 volumio ntpd[812]: Soliciting pool server 10.0.0.1 Sep 04 12:12:32 volumio ntpd[812]: Soliciting pool server 10.0.0.1 Sep 04 12:12:32 volumio tailscaled[20949]: Received error: PollNetMap: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:12:35 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:35 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): context deadline exceeded Sep 04 12:12:35 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:38 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:12:38 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:12:42 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:42 volumio tailscaled[20949]: control: controlhttp: failed dialing using DialPlan, falling back to DNS; errs=multiple errors: Sep 04 12:12:42 volumio tailscaled[20949]: connection attempts aborted by context: context deadline exceeded Sep 04 12:12:45 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:45 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:12:46 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): context deadline exceeded Sep 04 12:12:46 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:47 volumio tailscaled[20949]: control: lite map update error after 16.805s: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:12:49 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:12:49 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:12:52 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:53 volumio tailscaled[20949]: Received error: PollNetMap: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:12:53 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:12:56 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): context deadline exceeded Sep 04 12:12:56 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:12:56 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:12:59 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:12:59 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:12:59 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:13:00 volumio tailscaled[20949]: logtail: dial "log.tailscale.com:443" failed: dial tcp 10.0.0.1:443: i/o timeout (in 30s), trying bootstrap... Sep 04 12:13:01 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:03 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): dial tcp6 [2a00:dd80:3c::3d5]:443: connect: cannot assign requested address Sep 04 12:13:03 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:05 volumio tailscaled[20949]: control: controlhttp: failed dialing using DialPlan, falling back to DNS; errs=multiple errors: Sep 04 12:13:05 volumio tailscaled[20949]: connection attempts aborted by context: context deadline exceeded Sep 04 12:13:06 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:06 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:13:06 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:13:09 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:13:10 volumio tailscaled[20949]: control: lite map update error after 15.77s: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:13:11 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:13 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:13 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:13 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:13 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): dial tcp6 [2a00:dd80:3c::3d5]:443: connect: cannot assign requested address Sep 04 12:13:13 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:14 volumio ntpd[812]: Soliciting pool server 10.0.0.1 Sep 04 12:13:16 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:13:16 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:13:18 volumio tailscaled[20949]: Received error: PollNetMap: Post "https://controlplane.tailscale.com/machine/map": connection attempts aborted by context: context deadline exceeded Sep 04 12:13:18 volumio tailscaled[20949]: control: controlhttp: context aborted dialing Sep 04 12:13:18 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:18 volumio tailscaled[20949]: control: controlhttp: context aborted dialing Sep 04 12:13:18 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:19 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:13:23 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:23 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:24 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:24 volumio tailscaled[20949]: magicsock: [0x38a9c08] derp.Recv(derp-14): derphttp.Client.Recv connect to region 14 (ams): context deadline exceeded Sep 04 12:13:24 volumio volumio[2686]: info: CoreCommandRouter::volumioGetState Sep 04 12:13:24 volumio volumio[2686]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:24 volumio volumio[2686]: info: Listing playlists Sep 04 12:13:24 volumio volumio[2686]: info: Listing playlists Sep 04 12:13:26 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:26 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:26 volumio tailscaled[20949]: health(warnable=not-in-map-poll): ok Sep 04 12:13:26 volumio tailscaled[20949]: control: netmap: got new dial plan from control Sep 04 12:13:27 volumio tailscaled[20949]: netcheck: netcheck: UDP is blocked, trying HTTPS Sep 04 12:13:27 volumio tailscaled[20949]: netcheck: UDP is blocked, trying ICMP Sep 04 12:13:28 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-14 (ams) Sep 04 12:13:28 volumio tailscaled[20949]: magicsock: derp-14 connected; connGen=1 Sep 04 12:13:28 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:28 volumio tailscaled[20949]: [RATELIMIT] format("health(warnable=%s): ok") Sep 04 12:13:29 volumio tailscaled[20949]: magicsock: home DERP changing from derp-14 [26ms] to derp-8 [18ms] Sep 04 12:13:29 volumio tailscaled[20949]: magicsock: home is now derp-8 (lhr) Sep 04 12:13:29 volumio tailscaled[20949]: magicsock: adding connection to derp-8 for home-keep-alive Sep 04 12:13:29 volumio tailscaled[20949]: magicsock: 2 active derp conns: derp-8=cr0s,wr0s derp-14=cr9m0s,wr9m0s Sep 04 12:13:29 volumio tailscaled[20949]: derphttp.Client.Recv: connecting to derp-8 (lhr) Sep 04 12:13:29 volumio tailscaled[20949]: control: NetInfo: NetInfo{varies= hairpin= ipv6=false ipv6os=false udp=false icmpv4=true derp=#8 portmap= link="" firewallmode="ipt-default"} Sep 04 12:13:29 volumio tailscaled[20949]: magicsock: derp-8 connected; connGen=1 Sep 04 12:13:30 volumio tailscaled[20949]: trying bootstrapDNS("derp8f.tailscale.com", "176.58.88.183") for "log.tailscale.com" ... Sep 04 12:13:30 volumio wpa_supplicant[943]: wlan0: CTRL-EVENT-DISCONNECTED bssid=dc:62:79:2f:ce:72 reason=8 Sep 04 12:13:30 volumio dhcpcd[955]: wlan0: carrier lost Sep 04 12:13:30 volumio wpa_supplicant[943]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Sep 04 12:13:30 volumio wpa_supplicant[943]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=DE Sep 04 12:13:30 volumio avahi-daemon[643]: Withdrawing address record for 192.168.0.113 on wlan0. Sep 04 12:13:30 volumio tailscaled[20949]: monitor: RTM_DELROUTE: src=192.168.0.113/0, dst=192.168.0.255/32, gw=, outif=3, table=255 Sep 04 12:13:30 volumio tailscaled[20949]: monitor: RTM_DELROUTE: src=192.168.0.113/0, dst=192.168.0.113/32, gw=, outif=3, table=255 Sep 04 12:13:30 volumio tailscaled[20949]: monitor: RTM_DELROUTE: src=192.168.0.113/0, dst=192.168.0.0/24, gw=, outif=3, table=254 Sep 04 12:13:30 volumio tailscaled[20949]: monitor: RTM_DELROUTE: src=192.168.0.113/0, dst=, gw=192.168.0.47, outif=3, table=254 Sep 04 12:13:30 volumio avahi-daemon[643]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.113. Sep 04 12:13:30 volumio dhcpcd[955]: wlan0: deleting route to 192.168.0.0/24 Sep 04 12:13:30 volumio dhcpcd[955]: wlan0: deleting default route via 192.168.0.47 Sep 04 12:13:30 volumio avahi-daemon[643]: Interface wlan0.IPv4 no longer relevant for mDNS. Sep 04 12:13:30 volumio tailscaled[20949]: tsdial: closing system connection 192.168.0.113:36682->192.200.0.112:443 due to link change Sep 04 12:13:30 volumio tailscaled[20949]: LinkChange: all links down; pausing: interfaces.State{defaultRoute= ifs={tailscale0:[100.68.81.91/32]} v4=false v6=false} Sep 04 12:13:30 volumio tailscaled[20949]: magicsock: SetNetworkUp(false) Sep 04 12:13:30 volumio tailscaled[20949]: magicsock: closing connection to derp-14 (network-down), age 8m37s Sep 04 12:13:30 volumio tailscaled[20949]: magicsock: closing connection to derp-8 (network-down), age 1s Sep 04 12:13:30 volumio tailscaled[20949]: magicsock: 0 active derp conns Sep 04 12:13:30 volumio tailscaled[20949]: dns: Set: {DefaultResolvers:[] Routes:{barking-firefighter.ts.net.:[] ts.net.:[199.247.155.53 2620:111:8007::53]}+65arpa SearchDomains:[barking-firefighter.ts.net.] Hosts:10} Sep 04 12:13:30 volumio tailscaled[20949]: control: setPaused(true) Sep 04 12:13:30 volumio tailscaled[20949]: dns: Resolvercfg: {Routes:{.:[192.168.0.47 208.67.222.222 208.67.220.220] ts.net.:[199.247.155.53 2620:111:8007::53]} Hosts:10 LocalDomains:[barking-firefighter.ts.net.]+65arpa} Sep 04 12:13:30 volumio tailscaled[20949]: dns: OScfg: {Nameservers:[100.100.100.100] SearchDomains:[barking-firefighter.ts.net.] } Sep 04 12:13:30 volumio tailscaled[20949]: control: authRoutine: awaiting unpause Sep 04 12:13:30 volumio tailscaled[20949]: control: mapRoutine: paused Sep 04 12:13:30 volumio tailscaled[20949]: control: mapRoutine: awaiting unpause Sep 04 12:13:30 volumio tailscaled[20949]: trample: resolv.conf again matches expected content Sep 04 12:13:30 volumio tailscaled[20949]: control: updateRoutine: awaiting unpause Sep 04 12:13:30 volumio volumio[2686]: info: Discovery: A device disappeared from network Sep 04 12:13:30 volumio volumio[2686]: info: Discovery: Device volumio disappeared from network Sep 04 12:13:30 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:30 volumio tailscaled[20949]: wgengine: set DNS config again after major link change Sep 04 12:13:30 volumio tailscaled[20949]: onPortUpdate(port=41641, network=udp6) Sep 04 12:13:30 volumio tailscaled[20949]: onPortUpdate(port=41641, network=udp4) Sep 04 12:13:30 volumio tailscaled[20949]: Rebind; defIf="", ips=[] Sep 04 12:13:30 volumio tailscaled[20949]: magicsock: endpoints changed: 127.0.0.1:41641 (local) Sep 04 12:13:30 volumio tailscaled[20949]: trample: resolv.conf changed from what we expected. did some other program interfere? current contents: "# Generated by dhcpcd\n# OpenDNS nameservers\nnameserver 208.67.222.222\nnameserver 208.67.220.220\n" Sep 04 12:13:30 volumio tailscaled[20949]: health(warnable=resolv-conf-overwritten): error: Linux DNS config not ideal. /etc/resolv.conf overwritten. See https://tailscale.com/s/dns-fight Sep 04 12:13:31 volumio volumio[2686]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 12:13:31 volumio volumio[2686]: Error: send ENETUNREACH 255.255.255.255:3483 Sep 04 12:13:31 volumio volumio[2686]: at doSend (dgram.js:692:16) Sep 04 12:13:31 volumio volumio[2686]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Sep 04 12:13:31 volumio volumio[2686]: at afterDns (dgram.js:638:5) Sep 04 12:13:31 volumio volumio[2686]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Sep 04 12:13:31 volumio volumio[2686]: errno: -101, Sep 04 12:13:31 volumio volumio[2686]: code: 'ENETUNREACH', Sep 04 12:13:31 volumio volumio[2686]: syscall: 'send', Sep 04 12:13:31 volumio volumio[2686]: address: '255.255.255.255', Sep 04 12:13:31 volumio volumio[2686]: port: 3483 Sep 04 12:13:31 volumio volumio[2686]: } Sep 04 12:13:31 volumio volumio[2686]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 12:13:31 volumio sudo[2196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-04 12:12 Sep 04 12:13:31 volumio sudo[2196]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:31 volumio sudo[2196]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:31 volumio volumio-remote-updater[642]: [2025-09-04 12:13:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 04 12:13:31 volumio volumio-remote-updater[642]: [2025-09-04 12:13:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 04 12:13:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 04 12:13:31 volumio ntfs-3g[2759]: Unmounting /dev/sda1 (Seagate Expansion Drive) Sep 04 12:13:31 volumio go-librespot[2948]: time="2025-09-04T12:13:31+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Sep 04 12:13:31 volumio systemd[1]: media-Seagate_Expansion_Drive.mount: Succeeded. Sep 04 12:13:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 04 12:13:31 volumio systemd[1]: Started dynamicswap service. Sep 04 12:13:31 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 04 12:13:31 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 04 12:13:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5. Sep 04 12:13:31 volumio systemd[1]: Stopped Volumio Backend Module. Sep 04 12:13:31 volumio systemd[1]: Started Volumio Backend Module. Sep 04 12:13:31 volumio systemd[1]: Started dynamicswap service. Sep 04 12:13:31 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 04 12:13:32 volumio ntpd[812]: Deleting interface #7 wlan0, 192.168.0.113#123, interface stats: received=0, sent=74, dropped=0, active_time=517 secs Sep 04 12:13:32 volumio ntpd[812]: 162.159.200.123 local addr 192.168.0.113 -> Sep 04 12:13:32 volumio ntpd[812]: 77.104.162.218 local addr 192.168.0.113 -> Sep 04 12:13:32 volumio ntpd[812]: 131.111.8.60 local addr 192.168.0.113 -> Sep 04 12:13:32 volumio ntpd[812]: 139.162.219.252 local addr 192.168.0.113 -> Sep 04 12:13:32 volumio ntpd[812]: 213.5.132.231 local addr 192.168.0.113 -> Sep 04 12:13:32 volumio ntpd[812]: 95.215.175.2 local addr 192.168.0.113 -> Sep 04 12:13:32 volumio ntpd[812]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Sep 04 12:13:32 volumio volumio[2211]: info: ------------------------------------------- Sep 04 12:13:32 volumio volumio[2211]: info: ----- Volumio3 ---- Sep 04 12:13:32 volumio volumio[2211]: info: ------------------------------------------- Sep 04 12:13:32 volumio volumio[2211]: info: ----- System startup ---- Sep 04 12:13:32 volumio volumio[2211]: info: ------------------------------------------- Sep 04 12:13:33 volumio volumio[2211]: info: MYVOLUMIO Environment detected Sep 04 12:13:33 volumio volumio[2211]: info: Plugin folders cleanup Sep 04 12:13:33 volumio volumio[2211]: info: Scanning into folder /volumio/app/plugins/ Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category audio_interface Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category miscellanea Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category music_service Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category plugins.json Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category system_controller Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category user_interface Sep 04 12:13:33 volumio volumio[2211]: info: Scanning into folder /data/plugins/ Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category audio_interface Sep 04 12:13:33 volumio volumio[2211]: info: Scanning category music_service Sep 04 12:13:33 volumio volumio[2211]: info: Plugin folders cleanup completed Sep 04 12:13:33 volumio volumio[2211]: info: ------------------------------------------- Sep 04 12:13:33 volumio volumio[2211]: info: ----- Core plugins startup ---- Sep 04 12:13:33 volumio volumio[2211]: info: ------------------------------------------- Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugins from folder /volumio/app/plugins/ Sep 04 12:13:33 volumio volumio[2211]: info: Adding plugin upnp to MyMusic Plugins Sep 04 12:13:33 volumio volumio[2211]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 04 12:13:33 volumio volumio[2211]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugins from folder /data/plugins/ Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "system"... Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "appearance"... Sep 04 12:13:33 volumio tailscaled[20949]: bootstrapDNS("derp8f.tailscale.com", "176.58.88.183") for "log.tailscale.com" error: Get "https://derp8f.tailscale.com/bootstrap-dns?q=log.tailscale.com": context deadline exceeded Sep 04 12:13:33 volumio tailscaled[20949]: trying bootstrapDNS("derp9e.tailscale.com", "2607:f740:100::359") for "log.tailscale.com" ... Sep 04 12:13:33 volumio tailscaled[20949]: bootstrapDNS("derp9e.tailscale.com", "2607:f740:100::359") for "log.tailscale.com" error: Get "https://derp9e.tailscale.com/bootstrap-dns?q=log.tailscale.com": dial tcp [2607:f740:100::359]:443: connect: cannot assign requested address Sep 04 12:13:33 volumio tailscaled[20949]: trying bootstrapDNS("derp9f.tailscale.com", "209.177.156.197") for "log.tailscale.com" ... Sep 04 12:13:33 volumio tailscaled[20949]: bootstrapDNS("derp9f.tailscale.com", "209.177.156.197") for "log.tailscale.com" error: Get "https://derp9f.tailscale.com/bootstrap-dns?q=log.tailscale.com": dial tcp 209.177.156.197:443: connect: network is unreachable Sep 04 12:13:33 volumio tailscaled[20949]: trying bootstrapDNS("derp18d.tailscale.com", "2a00:dd80:3e::f2e") for "log.tailscale.com" ... Sep 04 12:13:33 volumio tailscaled[20949]: bootstrapDNS("derp18d.tailscale.com", "2a00:dd80:3e::f2e") for "log.tailscale.com" error: Get "https://derp18d.tailscale.com/bootstrap-dns?q=log.tailscale.com": dial tcp [2a00:dd80:3e::f2e]:443: connect: cannot assign requested address Sep 04 12:13:33 volumio tailscaled[20949]: trying bootstrapDNS("derp17d.tailscale.com", "208.111.40.216") for "log.tailscale.com" ... Sep 04 12:13:33 volumio tailscaled[20949]: bootstrapDNS("derp17d.tailscale.com", "208.111.40.216") for "log.tailscale.com" error: Get "https://derp17d.tailscale.com/bootstrap-dns?q=log.tailscale.com": dial tcp 208.111.40.216:443: connect: network is unreachable Sep 04 12:13:33 volumio tailscaled[20949]: trying bootstrapDNS("derp1c.tailscale.com", "2604:a880:800:10::7a0:e001") for "log.tailscale.com" ... Sep 04 12:13:33 volumio tailscaled[20949]: bootstrapDNS("derp1c.tailscale.com", "2604:a880:800:10::7a0:e001") for "log.tailscale.com" error: Get "https://derp1c.tailscale.com/bootstrap-dns?q=log.tailscale.com": dial tcp [2604:a880:800:10::7a0:e001]:443: connect: cannot assign requested address Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "network"... Sep 04 12:13:33 volumio volumio[2211]: info: Refreshing Cached IP Addresses Sep 04 12:13:33 volumio sudo[2238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 04 12:13:33 volumio sudo[2238]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:33 volumio sudo[2238]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:33 volumio sudo[2241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 04 12:13:33 volumio sudo[2241]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:33 volumio sudo[2241]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "services"... Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "alsa_controller"... Sep 04 12:13:33 volumio sudo[2250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 04 12:13:33 volumio sudo[2250]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:33 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "wizard"... Sep 04 12:13:33 volumio volumio[2211]: info: Loading plugin "networkfs"... Sep 04 12:13:34 volumio volumio[2211]: info: Starting Udev Watcher for removable devices Sep 04 12:13:34 volumio volumio[2211]: info: Ignoring mount for partition: boot Sep 04 12:13:34 volumio volumio[2211]: info: Ignoring mount for partition: volumio Sep 04 12:13:34 volumio volumio[2211]: info: Ignoring mount for partition: volumio_data Sep 04 12:13:34 volumio volumio[2211]: info: Mounting Device Seagate_Expansion_Drive Sep 04 12:13:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Sep 04 12:13:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Sep 04 12:13:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Sep 04 12:13:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Sep 04 12:13:35 volumio tailscaled[20949]: health(warnable=network-status): error: Tailscale cannot connect because the network is down. Check your Internet connection. Sep 04 12:13:35 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:35 volumio tailscaled[20949]: control: controlhttp: context aborted dialing Sep 04 12:13:35 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:36 volumio wpa_supplicant[943]: wlan0: Trying to associate with SSID 'OccamsRouter' Sep 04 12:13:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Sep 04 12:13:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Sep 04 12:13:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Sep 04 12:13:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Sep 04 12:13:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Sep 04 12:13:36 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Sep 04 12:13:36 volumio sudo[2270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Seagate_Expansion_Drive -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Sep 04 12:13:36 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:36 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:36 volumio sudo[2270]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:36 volumio volumio-remote-updater[642]: [2025-09-04 12:13:36] [connect] Successful connection Sep 04 12:13:36 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'Amsterdam' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:36 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:36 volumio dhcpcd[955]: wlan0: carrier acquired Sep 04 12:13:36 volumio wpa_supplicant[943]: wlan0: Associated with dc:62:79:2f:ce:73 Sep 04 12:13:36 volumio wpa_supplicant[943]: wlan0: CTRL-EVENT-CONNECTED - Connection to dc:62:79:2f:ce:73 completed [id=0 id_str=] Sep 04 12:13:36 volumio wpa_supplicant[943]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 04 12:13:36 volumio wpa_supplicant[943]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Sep 04 12:13:36 volumio dhcpcd[955]: wlan0: IAID dd:17:f5:26 Sep 04 12:13:36 volumio dhcpcd[955]: wlan0: carrier lost Sep 04 12:13:36 volumio dhcpcd[955]: wlan0: carrier acquired Sep 04 12:13:36 volumio dhcpcd[955]: wlan0: IAID dd:17:f5:26 Sep 04 12:13:36 volumio sudo[2250]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:37 volumio ntpd[812]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 04 12:13:37 volumio ntfs-3g[2285]: Version 2017.3.23AR.3 integrated FUSE 28 Sep 04 12:13:37 volumio ntfs-3g[2285]: Mounted /dev/sda1 (Read-Write, label "Seagate Expansion Drive", NTFS 3.1) Sep 04 12:13:37 volumio ntfs-3g[2285]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Sep 04 12:13:37 volumio ntfs-3g[2285]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Sep 04 12:13:37 volumio ntfs-3g[2285]: Global ownership and permissions enforced, configuration type 7 Sep 04 12:13:37 volumio sudo[2270]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:37 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "volumio_command_line_client"... Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "upnp"... Sep 04 12:13:37 volumio volumio[2211]: info: [1756984417259] Starting Upmpd Daemon Sep 04 12:13:37 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "my_music"... Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "mpd"... Sep 04 12:13:37 volumio dhcpcd[955]: wlan0: rebinding lease of 192.168.0.113 Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "upnp_browser"... Sep 04 12:13:37 volumio dhcpcd[955]: wlan0: soliciting an IPv6 router Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "alarm-clock"... Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "airplay_emulation"... Sep 04 12:13:37 volumio volumio[2211]: info: Starting Shairport Sync Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "last_100"... Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "webradio"... Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "i2s_dacs"... Sep 04 12:13:37 volumio volumio[2211]: info: I2S DAC not set, start Auto-detection Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "volumiodiscovery"... Sep 04 12:13:37 volumio volumio[2211]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:37 volumio volumio[2211]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:37 volumio node[2211]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:37 volumio volumio[2211]: *** WARNING *** For more information see Sep 04 12:13:37 volumio volumio[2211]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:37 volumio volumio[2211]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:37 volumio volumio[2211]: *** WARNING *** For more information see Sep 04 12:13:37 volumio node[2211]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:37 volumio node[2211]: *** WARNING *** For more information see Sep 04 12:13:37 volumio node[2211]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:37 volumio node[2211]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:37 volumio node[2211]: *** WARNING *** For more information see Sep 04 12:13:37 volumio volumio[2211]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 04 12:13:37 volumio volumio[2211]: info: Discovery: Started advertising with name: Volumio Sep 04 12:13:37 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 04 12:13:37 volumio volumio[2211]: info: Plugin jellyfin is not enabled Sep 04 12:13:37 volumio volumio[2211]: info: Loading plugin "spop"... Sep 04 12:13:38 volumio volumio[2211]: info: Loading plugin "squeezelite_mc"... Sep 04 12:13:38 volumio volumio[2211]: info: Loading plugin "outputs"... Sep 04 12:13:38 volumio volumio[2211]: info: Loading plugin "albumart"... Sep 04 12:13:38 volumio volumio[2211]: info: Plugin example_plugin is not enabled Sep 04 12:13:38 volumio volumio[2211]: info: Loading plugin "inputs"... Sep 04 12:13:38 volumio volumio[2211]: info: Loading plugin "updater_comm"... Sep 04 12:13:39 volumio ntpd[812]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 04 12:13:39 volumio volumio[2211]: info: Plugin mpdemulation is not enabled Sep 04 12:13:39 volumio volumio[2211]: info: Loading plugin "rest_api"... Sep 04 12:13:39 volumio volumio[2211]: info: Loading plugin "websocket"... Sep 04 12:13:39 volumio volumio[2211]: info: Starting Socket.io Server version 2.3.0 Sep 04 12:13:39 volumio volumio[2211]: info: Plugin mpdoutput is not enabled Sep 04 12:13:39 volumio volumio[2211]: info: Plugin minidlna is not enabled Sep 04 12:13:39 volumio volumio[2211]: info: Plugin volusonic is not enabled Sep 04 12:13:39 volumio volumio[2211]: info: Loading i18n strings for locale en Sep 04 12:13:39 volumio volumio[2211]: Updating browse sources language Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:39 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'London' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:39 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:39 volumio tailscaled[20949]: control: controlhttp: context aborted dialing Sep 04 12:13:39 volumio volumio[2211]: Forking 3 albumart workers Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::initPlayerControls Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: Express server listening on port 3000 Sep 04 12:13:39 volumio volumio[2211]: [Metrics] WebUI: 6s 670.62ms Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::resetVolumioState Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::getcurrentVolume Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::volumioRetrievevolume Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: Volumio Network Manager: Network status updated: 0 Sep 04 12:13:39 volumio volumio-remote-updater[642]: [2025-09-04 12:13:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756984416 101 Sep 04 12:13:39 volumio volumio[2211]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Sep 04 12:13:39 volumio volumio[2211]: info: Reloading queue from file Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::setRepeat null single undefined Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::pushState Sep 04 12:13:39 volumio volumio[2211]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::setRandom null Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::pushState Sep 04 12:13:39 volumio volumio[2211]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:39 volumio volumio[2211]: info: Setting Device type: Raspberry PI Sep 04 12:13:39 volumio volumio[2211]: info: VolumeController:: Volume=39 Mute =false Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::pushState Sep 04 12:13:39 volumio volumio[2211]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:39 volumio volumio[2211]: info: CoreStateMachine::updateTrackBlock Sep 04 12:13:39 volumio volumio[2211]: info: CorePlayQueue::getTrackBlock Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::volumioRetrievevolume Sep 04 12:13:39 volumio volumio[2211]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 04 12:13:39 volumio volumio[2211]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Sep 04 12:13:39 volumio volumio[2211]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 04 12:13:39 volumio volumio[2211]: info: Completed loading Core Plugins Sep 04 12:13:39 volumio volumio[2211]: info: Preparing to generate the ALSA configuration file Sep 04 12:13:39 volumio volumio[2211]: info: Asound.conf file unchanged, so no further update is needed Sep 04 12:13:39 volumio volumio[2211]: info: Output device has changed, restarting MPD Sep 04 12:13:39 volumio volumio[2211]: Starting albumart workers Sep 04 12:13:39 volumio volumio[2211]: info: Output device has changed, restarting Shairport Sync Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:39 volumio sudo[2332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 04 12:13:39 volumio sudo[2332]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:39 volumio sudo[2332]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:39 volumio sudo[2334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 04 12:13:39 volumio sudo[2334]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:39 volumio volumio[2211]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 12:13:39 volumio volumio[2211]: info: ___________ START PLUGINS ___________ Sep 04 12:13:39 volumio volumio[2211]: info: ControllerMpd::onStart: Initializing MPD Sep 04 12:13:39 volumio volumio[2211]: info: Creating MPD Configuration file Sep 04 12:13:39 volumio systemd[1]: Stopping Music Player Daemon... Sep 04 12:13:39 volumio volumio[2211]: Starting albumart workers Sep 04 12:13:39 volumio systemd[1]: mpd.service: Succeeded. Sep 04 12:13:39 volumio systemd[1]: Stopped Music Player Daemon. Sep 04 12:13:39 volumio sudo[2341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 04 12:13:39 volumio sudo[2341]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:39 volumio systemd[1]: Starting Music Player Daemon... Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 04 12:13:39 volumio volumio[2211]: info: [1756984419901] CoreMusicLibrary::Adding element Media Servers Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:39 volumio sudo[2341]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:39 volumio sudo[2346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 04 12:13:39 volumio sudo[2346]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:39 volumio volumio[2211]: Starting albumart workers Sep 04 12:13:39 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 04 12:13:39 volumio systemd[1]: mpd.service: Succeeded. Sep 04 12:13:39 volumio systemd[1]: Stopped Music Player Daemon. Sep 04 12:13:39 volumio systemd[1]: Starting Music Player Daemon... Sep 04 12:13:40 volumio sudo[2348]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 04 12:13:40 volumio sudo[2348]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:40 volumio sudo[2348]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:40 volumio volumio[2211]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 04 12:13:40 volumio volumio[2211]: info: [1756984420162] CoreMusicLibrary::Adding element Last_100 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 04 12:13:40 volumio volumio[2211]: info: [1756984420165] CoreMusicLibrary::Adding element Webradio Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 12:13:40 volumio volumio[2211]: info: Initializing BBC Radios Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: Creating Spotify config file Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'London' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:40 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:40 volumio tailscaled[20949]: health(warnable=no-derp-connection): error: Tailscale could not connect to the 'London' relay server. Your Internet connection might be down, or the server might be temporarily unavailable. Sep 04 12:13:40 volumio tailscaled[20949]: [RATELIMIT] format("health(warnable=%s): error: %s") Sep 04 12:13:40 volumio tailscaled[20949]: health: connectivity impacted; triggering captive portal detection Sep 04 12:13:40 volumio tailscaled[20949]: [RATELIMIT] format("health: connectivity impacted; triggering captive portal detection") Sep 04 12:13:40 volumio volumio[2211]: info: [squeezelite_mc] Starting proxy server... Sep 04 12:13:40 volumio volumio[2211]: info: Volumio Calling Home Sep 04 12:13:40 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:40 volumio volumio[2211]: info: [squeezelite_mc] Proxy server started on port 37771 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::volumioRetrievevolume Sep 04 12:13:40 volumio volumio[2211]: info: MPD Permissions set Sep 04 12:13:40 volumio volumio[2211]: info: MPD Permissions set Sep 04 12:13:40 volumio volumio[2211]: info: VolumeController:: Volume=39 Mute =false Sep 04 12:13:40 volumio volumio[2211]: info: CoreStateMachine::pushState Sep 04 12:13:40 volumio volumio[2211]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:40 volumio volumio[2211]: info: Spotify config file written Sep 04 12:13:40 volumio sudo[2397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 04 12:13:40 volumio sudo[2397]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:40 volumio volumio[2211]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio systemd[1]: Stopping go-librespot Daemon... Sep 04 12:13:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 04 12:13:40 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Sep 04 12:13:40 volumio systemd[1]: Stopped go-librespot Daemon. Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: No need to fix Spotify hosts Sep 04 12:13:40 volumio systemd[1]: Started go-librespot Daemon. Sep 04 12:13:40 volumio go-librespot[2403]: go-librespot daemon starting... Sep 04 12:13:40 volumio sudo[2397]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:40 volumio volumio[2211]: info: VolumeController:: Volume=39 Mute =false Sep 04 12:13:40 volumio volumio[2211]: info: CoreStateMachine::pushState Sep 04 12:13:40 volumio volumio[2211]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:40 volumio go-librespot[2403]: time="2025-09-04T12:13:40+01:00" level=info msg="running go-librespot 0.2.0" Sep 04 12:13:40 volumio go-librespot[2403]: time="2025-09-04T12:13:40+01:00" level=debug msg="app state loaded" Sep 04 12:13:40 volumio go-librespot[2403]: time="2025-09-04T12:13:40+01:00" level=debug msg="stored credentials not found" Sep 04 12:13:40 volumio go-librespot[2403]: time="2025-09-04T12:13:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 04 12:13:40 volumio go-librespot[2403]: time="2025-09-04T12:13:40+01:00" level=fatal msg="failed running zeroconf" 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" Sep 04 12:13:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 04 12:13:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 04 12:13:40 volumio volumio[2211]: info: [squeezelite_mc] Server discovery started Sep 04 12:13:40 volumio volumio[2211]: info: [squeezelite_mc] Player finder started Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:40 volumio volumio[2211]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Sep 04 12:13:40 volumio volumio[2211]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 12:13:40 volumio volumio[2211]: Error: send ENETUNREACH 255.255.255.255:3483 Sep 04 12:13:40 volumio volumio[2211]: at doSend (dgram.js:692:16) Sep 04 12:13:40 volumio volumio[2211]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Sep 04 12:13:40 volumio volumio[2211]: at afterDns (dgram.js:638:5) Sep 04 12:13:40 volumio volumio[2211]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Sep 04 12:13:40 volumio volumio[2211]: errno: -101, Sep 04 12:13:40 volumio volumio[2211]: code: 'ENETUNREACH', Sep 04 12:13:40 volumio volumio[2211]: syscall: 'send', Sep 04 12:13:40 volumio volumio[2211]: address: '255.255.255.255', Sep 04 12:13:40 volumio volumio[2211]: port: 3483 Sep 04 12:13:40 volumio volumio[2211]: } Sep 04 12:13:40 volumio volumio[2211]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 12:13:41 volumio mpd[2353]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 04 12:13:41 volumio mpd[2353]: output: No 'audio_output' defined in config file Sep 04 12:13:41 volumio mpd[2353]: output: Successfully detected a sndio audio device Sep 04 12:13:41 volumio mpd[2353]: zeroconf: No global port, disabling zeroconf Sep 04 12:13:41 volumio systemd[1]: Started Music Player Daemon. Sep 04 12:13:41 volumio sudo[2334]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:41 volumio sudo[2346]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:41 volumio sudo[2429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-04 12:12 Sep 04 12:13:41 volumio sudo[2429]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:41 volumio sudo[2429]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:41 volumio volumio-remote-updater[642]: [2025-09-04 12:13:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 04 12:13:41 volumio volumio-remote-updater[642]: [2025-09-04 12:13:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 04 12:13:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 04 12:13:41 volumio ntfs-3g[2285]: Unmounting /dev/sda1 (Seagate Expansion Drive) Sep 04 12:13:41 volumio systemd[1]: media-Seagate_Expansion_Drive.mount: Succeeded. Sep 04 12:13:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 04 12:13:41 volumio systemd[1]: Started dynamicswap service. Sep 04 12:13:41 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 04 12:13:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6. Sep 04 12:13:41 volumio systemd[1]: Stopped Volumio Backend Module. Sep 04 12:13:41 volumio systemd[1]: Started Volumio Backend Module. Sep 04 12:13:41 volumio systemd[1]: dynamicswap.service: Succeeded. Sep 04 12:13:42 volumio dhcpcd[955]: wlan0: probing for an IPv4LL address Sep 04 12:13:42 volumio volumio[2439]: info: ------------------------------------------- Sep 04 12:13:42 volumio volumio[2439]: info: ----- Volumio3 ---- Sep 04 12:13:42 volumio volumio[2439]: info: ------------------------------------------- Sep 04 12:13:42 volumio volumio[2439]: info: ----- System startup ---- Sep 04 12:13:42 volumio volumio[2439]: info: ------------------------------------------- Sep 04 12:13:42 volumio dhcpcd[955]: wlan0: DHCP lease expired Sep 04 12:13:42 volumio dhcpcd[955]: wlan0: soliciting a DHCP lease Sep 04 12:13:42 volumio volumio[2439]: info: MYVOLUMIO Environment detected Sep 04 12:13:42 volumio volumio[2439]: info: Plugin folders cleanup Sep 04 12:13:42 volumio volumio[2439]: info: Scanning into folder /volumio/app/plugins/ Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category audio_interface Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category miscellanea Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category music_service Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category plugins.json Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category system_controller Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category user_interface Sep 04 12:13:42 volumio volumio[2439]: info: Scanning into folder /data/plugins/ Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category audio_interface Sep 04 12:13:42 volumio volumio[2439]: info: Scanning category music_service Sep 04 12:13:42 volumio volumio[2439]: info: Plugin folders cleanup completed Sep 04 12:13:42 volumio volumio[2439]: info: ------------------------------------------- Sep 04 12:13:42 volumio volumio[2439]: info: ----- Core plugins startup ---- Sep 04 12:13:42 volumio volumio[2439]: info: ------------------------------------------- Sep 04 12:13:42 volumio volumio[2439]: info: Loading plugins from folder /volumio/app/plugins/ Sep 04 12:13:42 volumio volumio[2439]: info: Adding plugin upnp to MyMusic Plugins Sep 04 12:13:42 volumio volumio[2439]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 04 12:13:42 volumio volumio[2439]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 04 12:13:42 volumio volumio[2439]: info: Loading plugins from folder /data/plugins/ Sep 04 12:13:42 volumio volumio[2439]: info: Loading plugin "system"... Sep 04 12:13:42 volumio volumio[2439]: info: Loading plugin "appearance"... Sep 04 12:13:43 volumio volumio[2439]: info: Loading plugin "network"... Sep 04 12:13:43 volumio volumio[2439]: info: Refreshing Cached IP Addresses Sep 04 12:13:43 volumio sudo[2475]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 04 12:13:43 volumio sudo[2475]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:43 volumio sudo[2475]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:43 volumio sudo[2477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 04 12:13:43 volumio sudo[2477]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:43 volumio sudo[2477]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:43 volumio volumio[2439]: info: Loading plugin "services"... Sep 04 12:13:43 volumio volumio[2439]: info: Loading plugin "alsa_controller"... Sep 04 12:13:43 volumio sudo[2487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 04 12:13:43 volumio sudo[2487]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:43 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 12:13:43 volumio volumio[2439]: info: Loading plugin "wizard"... Sep 04 12:13:43 volumio volumio[2439]: info: Loading plugin "networkfs"... Sep 04 12:13:43 volumio volumio[2439]: info: Starting Udev Watcher for removable devices Sep 04 12:13:43 volumio volumio[2439]: info: Ignoring mount for partition: boot Sep 04 12:13:43 volumio volumio[2439]: info: Ignoring mount for partition: volumio Sep 04 12:13:43 volumio volumio[2439]: info: Ignoring mount for partition: volumio_data Sep 04 12:13:43 volumio volumio[2439]: info: Mounting Device Seagate_Expansion_Drive Sep 04 12:13:43 volumio sudo[2506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Seagate_Expansion_Drive -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Sep 04 12:13:43 volumio sudo[2506]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 04 12:13:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 04 12:13:44 volumio systemd[1]: Stopped go-librespot Daemon. Sep 04 12:13:44 volumio ntfs-3g[2510]: Version 2017.3.23AR.3 integrated FUSE 28 Sep 04 12:13:44 volumio ntfs-3g[2510]: Mounted /dev/sda1 (Read-Write, label "Seagate Expansion Drive", NTFS 3.1) Sep 04 12:13:44 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "volumio_command_line_client"... Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "upnp"... Sep 04 12:13:44 volumio volumio[2439]: info: [1756984424106] Starting Upmpd Daemon Sep 04 12:13:44 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "my_music"... Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "mpd"... Sep 04 12:13:44 volumio ntfs-3g[2510]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Sep 04 12:13:44 volumio systemd[1]: Started go-librespot Daemon. Sep 04 12:13:44 volumio ntfs-3g[2510]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Sep 04 12:13:44 volumio ntfs-3g[2510]: Global ownership and permissions enforced, configuration type 7 Sep 04 12:13:44 volumio sudo[2506]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:44 volumio go-librespot[2509]: go-librespot daemon starting... Sep 04 12:13:44 volumio go-librespot[2509]: time="2025-09-04T12:13:44+01:00" level=info msg="running go-librespot 0.2.0" Sep 04 12:13:44 volumio go-librespot[2509]: time="2025-09-04T12:13:44+01:00" level=debug msg="app state loaded" Sep 04 12:13:44 volumio go-librespot[2509]: time="2025-09-04T12:13:44+01:00" level=debug msg="stored credentials not found" Sep 04 12:13:44 volumio go-librespot[2509]: time="2025-09-04T12:13:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 04 12:13:44 volumio go-librespot[2509]: time="2025-09-04T12:13:44+01:00" level=fatal msg="failed running zeroconf" 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" Sep 04 12:13:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 04 12:13:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "upnp_browser"... Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "alarm-clock"... Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "airplay_emulation"... Sep 04 12:13:44 volumio volumio[2439]: info: Starting Shairport Sync Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "last_100"... Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "webradio"... Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "i2s_dacs"... Sep 04 12:13:44 volumio volumio[2439]: info: I2S DAC not set, start Auto-detection Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "volumiodiscovery"... Sep 04 12:13:44 volumio volumio[2439]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:44 volumio volumio[2439]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:44 volumio node[2439]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:44 volumio volumio[2439]: *** WARNING *** For more information see Sep 04 12:13:44 volumio volumio[2439]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:44 volumio volumio[2439]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:44 volumio volumio[2439]: *** WARNING *** For more information see Sep 04 12:13:44 volumio node[2439]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:44 volumio node[2439]: *** WARNING *** For more information see Sep 04 12:13:44 volumio node[2439]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 04 12:13:44 volumio node[2439]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 04 12:13:44 volumio node[2439]: *** WARNING *** For more information see Sep 04 12:13:44 volumio volumio[2439]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 04 12:13:44 volumio volumio[2439]: info: Discovery: Started advertising with name: Volumio Sep 04 12:13:44 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 04 12:13:44 volumio volumio[2439]: info: Plugin jellyfin is not enabled Sep 04 12:13:44 volumio volumio[2439]: info: Loading plugin "spop"... Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "squeezelite_mc"... Sep 04 12:13:45 volumio tailscaled[20949]: control: controlhttp: context aborted dialing Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "outputs"... Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "albumart"... Sep 04 12:13:45 volumio volumio[2439]: info: Plugin example_plugin is not enabled Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "inputs"... Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "updater_comm"... Sep 04 12:13:45 volumio volumio[2439]: info: Plugin mpdemulation is not enabled Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "rest_api"... Sep 04 12:13:45 volumio volumio[2439]: info: Loading plugin "websocket"... Sep 04 12:13:45 volumio volumio[2439]: info: Starting Socket.io Server version 2.3.0 Sep 04 12:13:45 volumio volumio[2439]: info: Plugin mpdoutput is not enabled Sep 04 12:13:45 volumio volumio[2439]: info: Plugin minidlna is not enabled Sep 04 12:13:45 volumio volumio[2439]: info: Plugin volusonic is not enabled Sep 04 12:13:45 volumio volumio[2439]: info: Loading i18n strings for locale en Sep 04 12:13:45 volumio volumio[2439]: Updating browse sources language Sep 04 12:13:45 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:45 volumio volumio[2439]: Forking 3 albumart workers Sep 04 12:13:45 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:45 volumio volumio[2439]: info: CoreCommandRouter::initPlayerControls Sep 04 12:13:45 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:45 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:45 volumio volumio[2439]: Express server listening on port 3000 Sep 04 12:13:45 volumio volumio[2439]: [Metrics] WebUI: 3s 905.83ms Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::resetVolumioState Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::getcurrentVolume Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioRetrievevolume Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:46 volumio volumio[2439]: info: Volumio Network Manager: Network status updated: 0 Sep 04 12:13:46 volumio volumio-remote-updater[642]: [2025-09-04 12:13:46] [connect] Successful connection Sep 04 12:13:46 volumio volumio[2439]: info: Reloading queue from file Sep 04 12:13:46 volumio volumio[2439]: info: VolumeController:: Volume=39 Mute =false Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::pushState Sep 04 12:13:46 volumio volumio[2439]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::updateTrackBlock Sep 04 12:13:46 volumio volumio[2439]: info: CorePlayQueue::getTrackBlock Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioRetrievevolume Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::setRepeat null single undefined Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::pushState Sep 04 12:13:46 volumio volumio[2439]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::setRandom null Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::pushState Sep 04 12:13:46 volumio volumio[2439]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:46 volumio volumio[2439]: info: Setting Device type: Raspberry PI Sep 04 12:13:46 volumio volumio[2439]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 04 12:13:46 volumio volumio[2439]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Sep 04 12:13:46 volumio volumio[2439]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 04 12:13:46 volumio volumio-remote-updater[642]: [2025-09-04 12:13:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756984426 101 Sep 04 12:13:46 volumio volumio[2439]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Sep 04 12:13:46 volumio volumio[2439]: info: Completed loading Core Plugins Sep 04 12:13:46 volumio volumio[2439]: Starting albumart workers Sep 04 12:13:46 volumio volumio[2439]: info: Preparing to generate the ALSA configuration file Sep 04 12:13:46 volumio volumio[2439]: info: VolumeController:: Volume=39 Mute =false Sep 04 12:13:46 volumio volumio[2439]: info: CoreStateMachine::pushState Sep 04 12:13:46 volumio volumio[2439]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:46 volumio volumio[2439]: info: Asound.conf file unchanged, so no further update is needed Sep 04 12:13:46 volumio volumio[2439]: info: Output device has changed, restarting MPD Sep 04 12:13:46 volumio volumio[2439]: Starting albumart workers Sep 04 12:13:46 volumio volumio[2439]: Starting albumart workers Sep 04 12:13:46 volumio sudo[2559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 04 12:13:46 volumio sudo[2559]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:46 volumio sudo[2559]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:46 volumio volumio[2439]: info: Output device has changed, restarting Shairport Sync Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:46 volumio sudo[2562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 04 12:13:46 volumio sudo[2562]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:46 volumio systemd[1]: Stopping Music Player Daemon... Sep 04 12:13:46 volumio systemd[1]: mpd.service: Succeeded. Sep 04 12:13:46 volumio systemd[1]: Stopped Music Player Daemon. Sep 04 12:13:46 volumio volumio[2439]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 12:13:46 volumio volumio[2439]: info: ___________ START PLUGINS ___________ Sep 04 12:13:46 volumio volumio[2439]: info: ControllerMpd::onStart: Initializing MPD Sep 04 12:13:46 volumio volumio[2439]: info: Creating MPD Configuration file Sep 04 12:13:46 volumio systemd[1]: Starting Music Player Daemon... Sep 04 12:13:46 volumio sudo[2570]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 04 12:13:46 volumio volumio[2439]: info: [1756984426832] CoreMusicLibrary::Adding element Media Servers Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:46 volumio sudo[2570]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:46 volumio sudo[2570]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:46 volumio sudo[2571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 04 12:13:46 volumio sudo[2571]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:46 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 04 12:13:46 volumio systemd[1]: mpd.service: Succeeded. Sep 04 12:13:46 volumio systemd[1]: Stopped Music Player Daemon. Sep 04 12:13:46 volumio systemd[1]: Starting Music Player Daemon... Sep 04 12:13:46 volumio volumio[2439]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:46 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:46 volumio sudo[2574]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 04 12:13:46 volumio sudo[2574]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:47 volumio sudo[2574]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:47 volumio volumio[2439]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 04 12:13:47 volumio volumio[2439]: info: [1756984427050] CoreMusicLibrary::Adding element Last_100 Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 04 12:13:47 volumio volumio[2439]: info: [1756984427053] CoreMusicLibrary::Adding element Webradio Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 12:13:47 volumio volumio[2439]: info: Initializing BBC Radios Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: Creating Spotify config file Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: [squeezelite_mc] Starting proxy server... Sep 04 12:13:47 volumio volumio[2439]: info: Volumio Calling Home Sep 04 12:13:47 volumio sudo[2487]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:47 volumio volumio[2439]: info: [squeezelite_mc] Proxy server started on port 37943 Sep 04 12:13:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 04 12:13:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 04 12:13:47 volumio systemd[1]: Stopped go-librespot Daemon. Sep 04 12:13:47 volumio systemd[1]: Started go-librespot Daemon. Sep 04 12:13:47 volumio go-librespot[2620]: go-librespot daemon starting... Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::volumioRetrievevolume Sep 04 12:13:47 volumio go-librespot[2620]: time="2025-09-04T12:13:47+01:00" level=info msg="running go-librespot 0.2.0" Sep 04 12:13:47 volumio go-librespot[2620]: time="2025-09-04T12:13:47+01:00" level=fatal msg="failed running zeroconf" 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" Sep 04 12:13:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 04 12:13:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 04 12:13:47 volumio volumio[2439]: info: MPD Permissions set Sep 04 12:13:47 volumio volumio[2439]: info: MPD Permissions set Sep 04 12:13:47 volumio volumio[2439]: info: Spotify config file written Sep 04 12:13:47 volumio sudo[2630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 04 12:13:47 volumio volumio[2439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 04 12:13:47 volumio sudo[2630]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio systemd[1]: Stopped go-librespot Daemon. Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: No need to fix Spotify hosts Sep 04 12:13:47 volumio systemd[1]: Started go-librespot Daemon. Sep 04 12:13:47 volumio go-librespot[2632]: go-librespot daemon starting... Sep 04 12:13:47 volumio sudo[2630]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:47 volumio go-librespot[2632]: time="2025-09-04T12:13:47+01:00" level=info msg="running go-librespot 0.2.0" Sep 04 12:13:47 volumio go-librespot[2632]: time="2025-09-04T12:13:47+01:00" level=debug msg="app state loaded" Sep 04 12:13:47 volumio go-librespot[2632]: time="2025-09-04T12:13:47+01:00" level=debug msg="stored credentials not found" Sep 04 12:13:47 volumio go-librespot[2632]: time="2025-09-04T12:13:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 04 12:13:47 volumio go-librespot[2632]: time="2025-09-04T12:13:47+01:00" level=fatal msg="failed running zeroconf" 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" Sep 04 12:13:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 04 12:13:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 04 12:13:47 volumio volumio[2439]: info: VolumeController:: Volume=39 Mute =false Sep 04 12:13:47 volumio volumio[2439]: info: CoreStateMachine::pushState Sep 04 12:13:47 volumio volumio[2439]: info: CorePlayQueue::getTrack 0 Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::volumioPushState Sep 04 12:13:47 volumio volumio[2439]: info: [squeezelite_mc] Server discovery started Sep 04 12:13:47 volumio volumio[2439]: info: [squeezelite_mc] Player finder started Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 12:13:47 volumio volumio[2439]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Sep 04 12:13:47 volumio volumio[2439]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 12:13:47 volumio volumio[2439]: Error: send ENETUNREACH 255.255.255.255:3483 Sep 04 12:13:47 volumio volumio[2439]: at doSend (dgram.js:692:16) Sep 04 12:13:47 volumio volumio[2439]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Sep 04 12:13:47 volumio volumio[2439]: at afterDns (dgram.js:638:5) Sep 04 12:13:47 volumio volumio[2439]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Sep 04 12:13:47 volumio volumio[2439]: errno: -101, Sep 04 12:13:47 volumio volumio[2439]: code: 'ENETUNREACH', Sep 04 12:13:47 volumio volumio[2439]: syscall: 'send', Sep 04 12:13:47 volumio volumio[2439]: address: '255.255.255.255', Sep 04 12:13:47 volumio volumio[2439]: port: 3483 Sep 04 12:13:47 volumio volumio[2439]: } Sep 04 12:13:47 volumio volumio[2439]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 12:13:47 volumio dhcpcd[955]: wlan0: using IPv4LL address 169.254.40.135 Sep 04 12:13:47 volumio avahi-daemon[643]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.40.135. Sep 04 12:13:47 volumio dhcpcd[955]: wlan0: adding route to 169.254.0.0/16 Sep 04 12:13:47 volumio dhcpcd[955]: wlan0: adding default route Sep 04 12:13:47 volumio avahi-daemon[643]: New relevant interface wlan0.IPv4 for mDNS. Sep 04 12:13:47 volumio avahi-daemon[643]: Registering new address record for 169.254.40.135 on wlan0.IPv4. Sep 04 12:13:47 volumio tailscaled[20949]: monitor: RTM_NEWROUTE: src=169.254.40.135/0, dst=, gw=, outif=3, table=254 Sep 04 12:13:47 volumio tailscaled[20949]: LinkChange: all links down; pausing: interfaces.State{defaultRoute=wlan0 ifs={tailscale0:[100.68.81.91/32] wlan0:[llu4]} v4=false v6=false} Sep 04 12:13:47 volumio tailscaled[20949]: dns: Set: {DefaultResolvers:[] Routes:{barking-firefighter.ts.net.:[] ts.net.:[199.247.155.53 2620:111:8007::53]}+65arpa SearchDomains:[barking-firefighter.ts.net.] Hosts:10} Sep 04 12:13:47 volumio tailscaled[20949]: dns: Resolvercfg: {Routes:{.:[208.67.222.222 208.67.220.220] ts.net.:[199.247.155.53 2620:111:8007::53]} Hosts:10 LocalDomains:[barking-firefighter.ts.net.]+65arpa} Sep 04 12:13:47 volumio tailscaled[20949]: dns: OScfg: {Nameservers:[100.100.100.100] SearchDomains:[barking-firefighter.ts.net.] } Sep 04 12:13:47 volumio tailscaled[20949]: [RATELIMIT] format("health(warnable=%s): ok") (4 dropped) Sep 04 12:13:47 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:47 volumio tailscaled[20949]: control: controlhttp: forcing port 443 dial due to recent noise dial Sep 04 12:13:47 volumio tailscaled[20949]: wgengine: set DNS config again after major link change Sep 04 12:13:47 volumio tailscaled[20949]: onPortUpdate(port=41641, network=udp6) Sep 04 12:13:47 volumio tailscaled[20949]: onPortUpdate(port=41641, network=udp4) Sep 04 12:13:47 volumio tailscaled[20949]: Rebind; defIf="wlan0", ips=[169.254.40.135/16] Sep 04 12:13:47 volumio tailscaled[20949]: magicsock: 0 active derp conns Sep 04 12:13:47 volumio tailscaled[20949]: magicsock: endpoints changed: 169.254.40.135:41641 (local) Sep 04 12:13:47 volumio tailscaled[20949]: health(warnable=no-derp-connection): ok Sep 04 12:13:47 volumio mpd[2580]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 04 12:13:47 volumio mpd[2580]: output: No 'audio_output' defined in config file Sep 04 12:13:47 volumio mpd[2580]: output: Successfully detected a sndio audio device Sep 04 12:13:47 volumio mpd[2580]: zeroconf: No global port, disabling zeroconf Sep 04 12:13:47 volumio systemd[1]: Started Music Player Daemon. Sep 04 12:13:47 volumio sudo[2562]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:47 volumio sudo[2571]: pam_unix(sudo:session): session closed for user root Sep 04 12:13:48 volumio dhcpcd[955]: wlan0: offered 192.168.0.113 from 192.168.0.1 Sep 04 12:13:48 volumio dhcpcd[955]: wlan0: ignoring offer of 192.168.0.113 from 192.168.0.1 Sep 04 12:13:48 volumio dhcpcd[955]: wlan0: probing address 192.168.0.113/24 Sep 04 12:13:48 volumio sudo[2675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-04 12:12 Sep 04 12:13:48 volumio sudo[2675]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"