Aug 25 05:46:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1913. Aug 25 05:46:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:01 volumio go-librespot[30822]: go-librespot daemon starting... Aug 25 05:46:01 volumio go-librespot[30823]: time="2026-08-25T05:46:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:01 volumio go-librespot[30823]: time="2026-08-25T05:46:01+02:00" level=debug msg="app state loaded" Aug 25 05:46:01 volumio go-librespot[30823]: time="2026-08-25T05:46:01+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:01 volumio go-librespot[30823]: time="2026-08-25T05:46:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:01 volumio go-librespot[30823]: time="2026-08-25T05:46:01+02: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" Aug 25 05:46:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:02 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:02 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1914. Aug 25 05:46:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:04 volumio go-librespot[30845]: go-librespot daemon starting... Aug 25 05:46:04 volumio go-librespot[30846]: time="2026-08-25T05:46:04+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:04 volumio go-librespot[30846]: time="2026-08-25T05:46:04+02:00" level=debug msg="app state loaded" Aug 25 05:46:04 volumio go-librespot[30846]: time="2026-08-25T05:46:04+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:04 volumio go-librespot[30846]: time="2026-08-25T05:46:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:04 volumio go-librespot[30846]: time="2026-08-25T05:46:04+02: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" Aug 25 05:46:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:05 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:05 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1915. Aug 25 05:46:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:07 volumio go-librespot[30854]: go-librespot daemon starting... Aug 25 05:46:07 volumio go-librespot[30855]: time="2026-08-25T05:46:07+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:07 volumio go-librespot[30855]: time="2026-08-25T05:46:07+02:00" level=debug msg="app state loaded" Aug 25 05:46:07 volumio go-librespot[30855]: time="2026-08-25T05:46:07+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:07 volumio go-librespot[30855]: time="2026-08-25T05:46:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:07 volumio go-librespot[30855]: time="2026-08-25T05:46:07+02: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" Aug 25 05:46:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:08 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:08 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1916. Aug 25 05:46:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:11 volumio go-librespot[30863]: go-librespot daemon starting... Aug 25 05:46:11 volumio go-librespot[30864]: time="2026-08-25T05:46:11+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:11 volumio go-librespot[30864]: time="2026-08-25T05:46:11+02:00" level=debug msg="app state loaded" Aug 25 05:46:11 volumio go-librespot[30864]: time="2026-08-25T05:46:11+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:11 volumio go-librespot[30864]: time="2026-08-25T05:46:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:11 volumio go-librespot[30864]: time="2026-08-25T05:46:11+02: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" Aug 25 05:46:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:11 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:11 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:12 volumio dhcpcd[732]: eth0: carrier acquired Aug 25 05:46:12 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Aug 25 05:46:12 volumio dhcpcd[732]: eth0: IAID eb:4c:78:ba Aug 25 05:46:12 volumio dhcpcd[732]: eth0: adding address fe80::ba27:ebff:fe4c:78ba Aug 25 05:46:12 volumio dhcpcd[732]: ipv6_addaddr1: Permission denied Aug 25 05:46:13 volumio volumio[28598]: info: Received Get System Info Aug 25 05:46:13 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 05:46:13 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 05:46:13 volumio volumio[28598]: info: Discovery: Getting this device information Aug 25 05:46:13 volumio volumio[28598]: info: CoreCommandRouter::volumioGetState Aug 25 05:46:13 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:13 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 05:46:13 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 05:46:13 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 05:46:13 volumio ifplugd(eth0)[1045]: Link beat detected. Aug 25 05:46:13 volumio ifplugd(eth0)[1045]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Aug 25 05:46:13 volumio ifplugd(eth0)[1045]: client: ifup: interface eth0 already configured Aug 25 05:46:13 volumio dhcpcd[732]: eth0: soliciting a DHCP lease Aug 25 05:46:13 volumio ifplugd(eth0)[1045]: Program executed successfully. Aug 25 05:46:13 volumio dhcpcd[732]: eth0: soliciting an IPv6 router Aug 25 05:46:14 volumio volumio5-onboarding[2575]: time=2026-08-25T05:46:14.311+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 05:46:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1917. Aug 25 05:46:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:14 volumio go-librespot[30895]: go-librespot daemon starting... Aug 25 05:46:14 volumio go-librespot[30896]: time="2026-08-25T05:46:14+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:14 volumio go-librespot[30896]: time="2026-08-25T05:46:14+02:00" level=debug msg="app state loaded" Aug 25 05:46:14 volumio go-librespot[30896]: time="2026-08-25T05:46:14+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:14 volumio go-librespot[30896]: time="2026-08-25T05:46:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:14 volumio go-librespot[30896]: time="2026-08-25T05:46:14+02: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" Aug 25 05:46:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: === SNM TRANSITION === Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: Previous ethernet state: disconnected Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: New ethernet state: connected Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: Single Network Mode: enabled Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: First start: no Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: === END TRANSITION === Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: SNM: Ethernet connected, switching to ethernet (WiFi scan mode) Aug 25 05:46:14 volumio sudo[30906]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd -k wlan0 Aug 25 05:46:14 volumio sudo[30906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 05:46:14 volumio dhcpcd[30907]: dhcpcd not running Aug 25 05:46:14 volumio sudo[30906]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:14 volumio wireless.js[701]: dhcpcd not running Aug 25 05:46:14 volumio wireless.js[701]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Aug 25 05:46:14 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:14 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:15 volumio sudo[30915]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 25 05:46:15 volumio sudo[30915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 05:46:15 volumio sudo[30915]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:15 volumio sudo[30917]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 25 05:46:15 volumio sudo[30917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 05:46:15 volumio sudo[30917]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:15 volumio wireless.js[701]: WIRELESS.JS - INFO: Cleaning previous... Aug 25 05:46:15 volumio sudo[30920]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 25 05:46:15 volumio sudo[30920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 05:46:15 volumio sudo[30920]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:15 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 25 05:46:15 volumio wireless.js[701]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 25 05:46:15 volumio wireless.js[701]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 3ms Aug 25 05:46:15 volumio wireless.js[701]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: b8:27:eb:19:2d:ef) Aug 25 05:46:15 volumio sudo[30927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 25 05:46:15 volumio sudo[30927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 05:46:15 volumio sudo[30927]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:16 volumio sudo[30935]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 25 05:46:16 volumio sudo[30935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 05:46:16 volumio volumio[28598]: info: Received Get System Info Aug 25 05:46:16 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 05:46:16 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 05:46:16 volumio volumio[28598]: info: Discovery: Getting this device information Aug 25 05:46:16 volumio volumio[28598]: info: CoreCommandRouter::volumioGetState Aug 25 05:46:16 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:16 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 05:46:16 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 05:46:16 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 05:46:16 volumio sudo[30935]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:16 volumio wireless.js[701]: WIRELESS.JS - INFO: Regdomain already correct: DE Aug 25 05:46:16 volumio wireless.js[701]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability Aug 25 05:46:16 volumio wireless.js[701]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) Aug 25 05:46:16 volumio wireless.js[701]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active Aug 25 05:46:16 volumio sudo[30944]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 25 05:46:16 volumio sudo[30944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 05:46:16 volumio sudo[30944]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:17 volumio sudo[30947]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 25 05:46:17 volumio sudo[30947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 05:46:17 volumio sudo[30947]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:17 volumio wpa_supplicant[30950]: Successfully initialized wpa_supplicant Aug 25 05:46:17 volumio volumio5-onboarding[2575]: time=2026-08-25T05:46:17.238+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 05:46:17 volumio wpa_supplicant[30953]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Aug 25 05:46:17 volumio wireless.js[701]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 2724ms Aug 25 05:46:17 volumio wireless.js[701]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable Aug 25 05:46:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1918. Aug 25 05:46:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:17 volumio wireless.js[701]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 25 05:46:17 volumio kernel: Aug 25 05:46:17 volumio kernel: ERROR::dwc_otg_hcd_urb_enqueue:502: Not connected Aug 25 05:46:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:17 volumio go-librespot[30971]: go-librespot daemon starting... Aug 25 05:46:17 volumio volumio[28598]: info: Received Get System Info Aug 25 05:46:17 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 05:46:17 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 05:46:17 volumio volumio[28598]: info: Discovery: Getting this device information Aug 25 05:46:17 volumio volumio[28598]: info: CoreCommandRouter::volumioGetState Aug 25 05:46:17 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:17 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 05:46:17 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 05:46:17 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 05:46:17 volumio volumio5-onboarding[2575]: time=2026-08-25T05:46:17.618+02:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get Ethernet info: failed SIOCETHTOOL syscall for eth0, errno=no such device" Aug 25 05:46:17 volumio go-librespot[30972]: time="2026-08-25T05:46:17+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:17 volumio go-librespot[30972]: time="2026-08-25T05:46:17+02:00" level=debug msg="app state loaded" Aug 25 05:46:17 volumio go-librespot[30972]: time="2026-08-25T05:46:17+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:17 volumio go-librespot[30972]: time="2026-08-25T05:46:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:17 volumio go-librespot[30972]: time="2026-08-25T05:46:17+02: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" Aug 25 05:46:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:17 volumio dhcpcd[732]: eth0: carrier lost Aug 25 05:46:17 volumio kernel: usb 1-1: USB disconnect, device number 28 Aug 25 05:46:17 volumio kernel: usb 1-1.1: USB disconnect, device number 29 Aug 25 05:46:17 volumio kernel: smsc95xx 1-1.1:1.0 eth0: unregister 'smsc95xx' usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet Aug 25 05:46:17 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Aug 25 05:46:17 volumio kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Aug 25 05:46:17 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:17 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:17 volumio kernel: usb 1-1.4: USB disconnect, device number 30 Aug 25 05:46:18 volumio kernel: Indeed it is in host mode hprt0 = 00021501 Aug 25 05:46:18 volumio ifplugd(eth0)[1045]: Link beat lost. Aug 25 05:46:18 volumio volumio[28598]: info: Received Get System Info Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 05:46:18 volumio volumio[28598]: info: Discovery: Getting this device information Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::volumioGetState Aug 25 05:46:18 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 05:46:18 volumio volumio5-onboarding[2575]: time=2026-08-25T05:46:18.270+02:00 level=ERROR msg="failed to broadcast Ethernet info" component=state error="failed to get ethernet info: failed SIOCETHTOOL syscall for eth0, errno=no such device" Aug 25 05:46:18 volumio volumio5-onboarding[2575]: time=2026-08-25T05:46:18.292+02:00 level=ERROR msg="failed to update discovery on Ethernet info change" error="failed to get Ethernet info: failed SIOCETHTOOL syscall for eth0, errno=no such device" Aug 25 05:46:18 volumio kernel: usb 1-1: new high-speed USB device number 31 using dwc_otg Aug 25 05:46:18 volumio kernel: Indeed it is in host mode hprt0 = 00001101 Aug 25 05:46:18 volumio volumio[28598]: info: Received Get System Info Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 05:46:18 volumio volumio[28598]: info: Discovery: Getting this device information Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::volumioGetState Aug 25 05:46:18 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 05:46:18 volumio volumio[28598]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 05:46:18 volumio volumio5-onboarding[2575]: time=2026-08-25T05:46:18.535+02:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get Ethernet info: failed SIOCETHTOOL syscall for eth0, errno=no such device" Aug 25 05:46:18 volumio kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 Aug 25 05:46:18 volumio kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Aug 25 05:46:18 volumio kernel: hub 1-1:1.0: USB hub found Aug 25 05:46:18 volumio kernel: hub 1-1:1.0: 5 ports detected Aug 25 05:46:18 volumio volumio[28598]: info: Partition removed: {"syspath":"/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-id/usb-Wilk_USB_DISK_3.0_070107C897AD5B03-0:0-part1 /dev/disk/by-path/platform-3f980000.usb-usb-0:1.4:1.0-scsi-0:0:0:0-part1 /dev/disk/by-partuuid/64c22e5a-01 /dev/disk/by-uuid/3AA2-24B3 /dev/disk/by-label/USB\\x20DISK","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"36","ID_BUS":"usb","ID_FS_LABEL":"USB_DISK","ID_FS_LABEL_ENC":"USB\\x20DISK","ID_FS_TYPE":"exfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"3AA2-24B3","ID_FS_UUID_ENC":"3AA2-24B3","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"USB_DISK_3.0","ID_MODEL_ENC":"USB\\x20DISK\\x203.0\\x20\\x20\\x20\\x20","ID_MODEL_ID":"6300","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"6656","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"241747456","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"64c22e5a-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"64c22e5a","ID_PATH":"platform-3f980000.usb-usb-0:1.4:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-3f980000_usb-usb-0_1_4_1_0-scsi-0_0_0_0","ID_REVISION":"PMAP","ID_SERIAL":"Wilk_USB_DISK_3.0_070107C897AD5B03-0:0","ID_SERIAL_SHORT":"070107C897AD5B03","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INSTANCE":"0:0","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"USB_DISK_3.0","ID_USB_MODEL_ENC":"USB\\x20DISK\\x203.0\\x20\\x20\\x20\\x20","ID_USB_MODEL_ID":"6300","ID_USB_REVISION":"PMAP","ID_USB_SERIAL":"Wilk_USB_DISK_3.0_070107C897AD5B03-0:0","ID_USB_SERIAL_SHORT":"070107C897AD5B03","ID_USB_TYPE":"disk","ID_USB_VENDOR":"Wilk","ID_USB_VENDOR_ENC":"Wilk\\x20\\x20\\x20\\x20","ID_USB_VENDOR_ID":"13fe","ID_VENDOR":"Wilk","ID_VENDOR_ENC":"Wilk\\x20\\x20\\x20\\x20","ID_VENDOR_ID":"13fe","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"2680","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"82106479"} Aug 25 05:46:18 volumio dhcpcd[732]: eth0: removing interface Aug 25 05:46:18 volumio systemd[1]: Stopping ifup@eth0.service - ifup for eth0... Aug 25 05:46:18 volumio sudo[31040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda1 Aug 25 05:46:18 volumio sudo[31040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 05:46:18 volumio systemd[1]: media-USB_DISK.mount: Deactivated successfully. Aug 25 05:46:18 volumio sudo[31040]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:18 volumio dhcpcd[31055]: dhcpcd not running Aug 25 05:46:18 volumio ifdown[31055]: dhcpcd not running Aug 25 05:46:18 volumio ifdown[31057]: Cannot find device "eth0" Aug 25 05:46:18 volumio kernel: usb 1-1.1: new high-speed USB device number 32 using dwc_otg Aug 25 05:46:18 volumio systemd[1]: ifup@eth0.service: Deactivated successfully. Aug 25 05:46:18 volumio systemd[1]: Stopped ifup@eth0.service - ifup for eth0. Aug 25 05:46:18 volumio kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Aug 25 05:46:18 volumio kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Aug 25 05:46:18 volumio kernel: smsc95xx v2.0.0 Aug 25 05:46:18 volumio mtp-probe[31071]: checking bus 1, device 32: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1" Aug 25 05:46:19 volumio mtp-probe[31071]: bus: 1, device: 32 was not an MTP device Aug 25 05:46:19 volumio kernel: SMSC LAN8700 usb-001:032:01: attached PHY driver (mii_bus:phy_addr=usb-001:032:01, irq=199) Aug 25 05:46:19 volumio kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:4c:78:ba Aug 25 05:46:19 volumio (udev-worker)[31002]: Network interface NamePolicy= disabled on kernel command line. Aug 25 05:46:19 volumio systemd[1]: Expecting device sys-subsystem-net-devices-eth0.device - /sys/subsystem/net/devices/eth0... Aug 25 05:46:19 volumio kernel: usb 1-1.4: new high-speed USB device number 33 using dwc_otg Aug 25 05:46:19 volumio kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Aug 25 05:46:19 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Aug 25 05:46:19 volumio systemd[1]: Found device sys-subsystem-net-devices-eth0.device - SMSC9512/9514 Fast Ethernet Adapter. Aug 25 05:46:19 volumio mtp-probe[31085]: checking bus 1, device 32: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1" Aug 25 05:46:19 volumio mtp-probe[31085]: bus: 1, device: 32 was not an MTP device Aug 25 05:46:19 volumio systemd[1]: Started ifup@eth0.service - ifup for eth0. Aug 25 05:46:19 volumio dhcpcd[732]: eth0: waiting for carrier Aug 25 05:46:19 volumio kernel: usb 1-1.4: New USB device found, idVendor=13fe, idProduct=6300, bcdDevice= 1.10 Aug 25 05:46:19 volumio kernel: usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 25 05:46:19 volumio kernel: usb 1-1.4: Product: USB DISK 3.0 Aug 25 05:46:19 volumio kernel: usb 1-1.4: Manufacturer: Wilk Aug 25 05:46:19 volumio kernel: usb 1-1.4: SerialNumber: 070107C897AD5B03 Aug 25 05:46:19 volumio kernel: usb-storage 1-1.4:1.0: USB Mass Storage device detected Aug 25 05:46:19 volumio kernel: scsi host0: usb-storage 1-1.4:1.0 Aug 25 05:46:19 volumio mtp-probe[31107]: checking bus 1, device 33: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4" Aug 25 05:46:19 volumio mtp-probe[31107]: bus: 1, device: 33 was not an MTP device Aug 25 05:46:19 volumio sh[31114]: sending commands to dhcpcd process Aug 25 05:46:19 volumio dhcpcd[732]: ps_ctl_dispatch: cannot handle another client Aug 25 05:46:19 volumio dhcpcd[732]: control_free: No such file or directory Aug 25 05:46:19 volumio mtp-probe[31116]: checking bus 1, device 33: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4" Aug 25 05:46:19 volumio mtp-probe[31116]: bus: 1, device: 33 was not an MTP device Aug 25 05:46:19 volumio sh[31142]: eth0=eth0 Aug 25 05:46:20 volumio kernel: scsi 0:0:0:0: Direct-Access Wilk USB DISK 3.0 PMAP PQ: 0 ANSI: 6 Aug 25 05:46:20 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Aug 25 05:46:20 volumio dhcpcd[732]: eth0: carrier acquired Aug 25 05:46:20 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Aug 25 05:46:20 volumio dhcpcd[732]: eth0: IAID eb:4c:78:ba Aug 25 05:46:20 volumio dhcpcd[732]: eth0: adding address fe80::ba27:ebff:fe4c:78ba Aug 25 05:46:20 volumio dhcpcd[732]: ipv6_addaddr1: Permission denied Aug 25 05:46:20 volumio kernel: sd 0:0:0:0: [sda] 241754112 512-byte logical blocks: (124 GB/115 GiB) Aug 25 05:46:20 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off Aug 25 05:46:20 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 45 00 00 00 Aug 25 05:46:20 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA Aug 25 05:46:20 volumio kernel: sda: sda1 Aug 25 05:46:20 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Aug 25 05:46:20 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:20 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1919. Aug 25 05:46:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:20 volumio go-librespot[31145]: go-librespot daemon starting... Aug 25 05:46:20 volumio go-librespot[31146]: time="2026-08-25T05:46:20+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:20 volumio go-librespot[31146]: time="2026-08-25T05:46:20+02:00" level=debug msg="app state loaded" Aug 25 05:46:20 volumio go-librespot[31146]: time="2026-08-25T05:46:20+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:20 volumio volumio[28598]: info: Mounting Device USB_DISK Aug 25 05:46:21 volumio go-librespot[31146]: time="2026-08-25T05:46:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:21 volumio go-librespot[31146]: time="2026-08-25T05:46:21+02: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" Aug 25 05:46:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:21 volumio sudo[31160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/USB_DISK -o noatime Aug 25 05:46:21 volumio sudo[31160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 05:46:21 volumio dhcpcd[732]: eth0: soliciting an IPv6 router Aug 25 05:46:21 volumio sudo[31160]: pam_unix(sudo:session): session closed for user root Aug 25 05:46:21 volumio volumio[28598]: info: Scanning new location : "USB/USB_DISK" Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: Aug 25 05:46:21 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: Aug 25 05:46:21 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio ifplugd(eth0)[1045]: Link beat detected. Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: Aug 25 05:46:21 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 25 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 22 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 21 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 18 milliseconds Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: Command Router : Notfying DB Updatetrue Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: Command Router : Notfying DB Updatetrue Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:21 volumio volumio[28598]: info: ------------------------------ 272ms Aug 25 05:46:21 volumio volumio[28598]: info: ------------------------------ 266ms Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 270 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 259 milliseconds Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: Command Router : Notfying DB Updatetrue Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:21 volumio volumio[28598]: info: ------------------------------ 328ms Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: Aug 25 05:46:21 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: Aug 25 05:46:21 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: Aug 25 05:46:21 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 12 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 11 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 10 milliseconds Aug 25 05:46:21 volumio volumio[28598]: info: sendMpdCommand status took 6 milliseconds Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: Command Router : Notfying DB Updatefalse Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: Command Router : Notfying DB Updatefalse Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:21 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:21 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:21 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:21 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:21 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:22 volumio volumio[28598]: info: ------------------------------ 118ms Aug 25 05:46:22 volumio volumio[28598]: info: ------------------------------ 114ms Aug 25 05:46:22 volumio volumio[28598]: info: sendMpdCommand status took 113 milliseconds Aug 25 05:46:22 volumio volumio[28598]: info: sendMpdCommand status took 111 milliseconds Aug 25 05:46:22 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:22 volumio volumio[28598]: info: Command Router : Notfying DB Updatefalse Aug 25 05:46:22 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:22 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:22 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:22 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:22 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:22 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:22 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:22 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:22 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:22 volumio volumio[28598]: info: ------------------------------ 171ms Aug 25 05:46:22 volumio dhcpcd[732]: eth0: soliciting a DHCP lease Aug 25 05:46:22 volumio dhcpcd[732]: eth0: offered 192.168.1.212 from 192.168.1.1 Aug 25 05:46:22 volumio dhcpcd[732]: eth0: probing address 192.168.1.212/24 Aug 25 05:46:22 volumio volumio[28598]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/USB_DISK Aug 25 05:46:23 volumio volumio[28598]: info: Scanning removed location : "USB/USB_DISK" Aug 25 05:46:23 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: Aug 25 05:46:23 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: Aug 25 05:46:23 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: Aug 25 05:46:23 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 14 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 10 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 10 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 9 milliseconds Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:23 volumio volumio[28598]: info: Command Router : Notfying DB Updatetrue Aug 25 05:46:23 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:23 volumio volumio[28598]: info: Command Router : Notfying DB Updatetrue Aug 25 05:46:23 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:23 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:23 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:23 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:23 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:23 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:23 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:23 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:23 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:23 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:23 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:23 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:23 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:23 volumio volumio[28598]: info: ------------------------------ 148ms Aug 25 05:46:23 volumio volumio[28598]: info: ------------------------------ 145ms Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: Aug 25 05:46:23 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: Aug 25 05:46:23 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: Aug 25 05:46:23 volumio volumio[28598]: ---------------------------- MPD announces state update: update Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 160 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 157 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: ControllerMpd::getState Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::sendMpdCommand status Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 13 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 11 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 10 milliseconds Aug 25 05:46:23 volumio volumio[28598]: info: sendMpdCommand status took 8 milliseconds Aug 25 05:46:23 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio volumio[28598]: info: Command Router : Notfying DB Updatetrue Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio volumio[28598]: info: Command Router : Notfying DB Updatefalse Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1920. Aug 25 05:46:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:24 volumio volumio[28598]: info: Command Router : Notfying DB Updatefalse Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:24 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:24 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:24 volumio go-librespot[31224]: go-librespot daemon starting... Aug 25 05:46:24 volumio volumio[28598]: info: ------------------------------ 342ms Aug 25 05:46:24 volumio volumio[28598]: info: ------------------------------ 193ms Aug 25 05:46:24 volumio volumio[28598]: info: ------------------------------ 189ms Aug 25 05:46:24 volumio go-librespot[31225]: time="2026-08-25T05:46:24+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:24 volumio go-librespot[31225]: time="2026-08-25T05:46:24+02:00" level=debug msg="app state loaded" Aug 25 05:46:24 volumio go-librespot[31225]: time="2026-08-25T05:46:24+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:24 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:24 volumio volumio[28598]: info: sendMpdCommand status took 233 milliseconds Aug 25 05:46:24 volumio volumio[28598]: info: sendMpdCommand status took 230 milliseconds Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio volumio[28598]: info: Command Router : Notfying DB Updatefalse Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::Close All Modals sent Aug 25 05:46:24 volumio volumio[28598]: verbose: ControllerMpd::parseState Aug 25 05:46:24 volumio go-librespot[31225]: time="2026-08-25T05:46:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:24 volumio volumio[28598]: info: ControllerMpd::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::servicePushState Aug 25 05:46:24 volumio volumio[28598]: info: CoreStateMachine::pushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio go-librespot[31225]: time="2026-08-25T05:46:24+02: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" Aug 25 05:46:24 volumio volumio[28598]: info: CoreCommandRouter::volumioPushState Aug 25 05:46:24 volumio volumio[28598]: info: CorePlayQueue::getTrack 0 Aug 25 05:46:24 volumio volumio[28598]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current soundcloud Received mpd Aug 25 05:46:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:24 volumio volumio[28598]: info: ------------------------------ 296ms Aug 25 05:46:27 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:27 volumio volumio[28598]: info: Error connecting to go-librespot Websocket: AggregateError Aug 25 05:46:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1921. Aug 25 05:46:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:27 volumio go-librespot[31236]: go-librespot daemon starting... Aug 25 05:46:27 volumio go-librespot[31237]: time="2026-08-25T05:46:27+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:27 volumio go-librespot[31237]: time="2026-08-25T05:46:27+02:00" level=debug msg="app state loaded" Aug 25 05:46:27 volumio go-librespot[31237]: time="2026-08-25T05:46:27+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:27 volumio go-librespot[31237]: time="2026-08-25T05:46:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:27 volumio go-librespot[31237]: time="2026-08-25T05:46:27+02: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" Aug 25 05:46:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:27 volumio dhcpcd[732]: eth0: leased 192.168.1.212 for 7200 seconds Aug 25 05:46:27 volumio avahi-daemon[681]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.212. Aug 25 05:46:27 volumio avahi-daemon[681]: New relevant interface eth0.IPv4 for mDNS. Aug 25 05:46:27 volumio avahi-daemon[681]: Registering new address record for 192.168.1.212 on eth0.IPv4. Aug 25 05:46:27 volumio dhcpcd[732]: eth0: adding route to 192.168.1.0/24 Aug 25 05:46:27 volumio dhcpcd[732]: eth0: adding default route via 192.168.1.1 Aug 25 05:46:27 volumio systemd[1]: welcome.service: Deactivated successfully. Aug 25 05:46:27 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 25 05:46:27 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 25 05:46:27 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 25 05:46:27 volumio welcome[31265]: Resolved ip:[1] 192.168.1.212 Aug 25 05:46:27 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 25 05:46:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Aug 25 05:46:28 volumio ntpd[1025]: IO: Listen normally on 3 eth0 192.168.1.212:123 Aug 25 05:46:28 volumio ntpd[1025]: IO: new interface(s) found: waking up resolver Aug 25 05:46:28 volumio ntpd[1025]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 05:46:30 volumio volumio[28598]: info: Initializing connection to go-librespot Websocket Aug 25 05:46:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1922. Aug 25 05:46:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 25 05:46:30 volumio go-librespot[31285]: go-librespot daemon starting... Aug 25 05:46:30 volumio go-librespot[31286]: time="2026-08-25T05:46:30+02:00" level=info msg="running go-librespot 0.7.1" Aug 25 05:46:30 volumio go-librespot[31286]: time="2026-08-25T05:46:30+02:00" level=debug msg="app state loaded" Aug 25 05:46:30 volumio go-librespot[31286]: time="2026-08-25T05:46:30+02:00" level=debug msg="stored credentials not found" Aug 25 05:46:30 volumio go-librespot[31286]: time="2026-08-25T05:46:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 25 05:46:32 volumio volumio[28598]: info: Volumio Network Manager: Network status updated: 1 Aug 25 05:46:47 volumio go-librespot[31286]: time="2026-08-25T05:46:47+02:00" level=debug msg="new websocket client" Aug 25 05:46:47 volumio volumio[28598]: info: Connection to go-librespot Websocket established Aug 25 05:46:50 volumio volumio[28598]: info: Getting Spotify volume Aug 25 05:46:57 volumio ntpd[1025]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 25 05:46:57 volumio ntpd[1025]: DNS: dns_check: DNS error: -11, System error Aug 25 05:46:57 volumio ntpd[1025]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Aug 25 05:46:57 volumio ntpd[1025]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 05:46:58 volumio go-librespot[31286]: time="2026-08-25T05:46:58+02: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" Aug 25 05:46:58 volumio volumio[28598]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 05:46:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 25 05:46:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 25 05:46:58 volumio volumio[28598]: Error: socket hang up Aug 25 05:46:58 volumio volumio[28598]: at connResetException (node:internal/errors:720:14) Aug 25 05:46:58 volumio volumio[28598]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 25 05:46:58 volumio volumio[28598]: at Socket.emit (node:events:526:35) Aug 25 05:46:58 volumio volumio[28598]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 25 05:46:58 volumio volumio[28598]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 25 05:46:58 volumio volumio[28598]: code: 'ECONNRESET', Aug 25 05:46:58 volumio volumio[28598]: response: undefined Aug 25 05:46:58 volumio volumio[28598]: } Aug 25 05:46:58 volumio volumio[28598]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 05:47:00 volumio sudo[31353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-25 05:46' Aug 25 05:47:00 volumio sudo[31353]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"