Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-DISCONNECTED bssid=70:7d:a1:1c:c4:77 reason=15 Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="telenet-Gubbi" auth_failures=2 duration=38 reason=WRONG_KEY Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: BSSID 70:7d:a1:1c:c4:77 ignore list count incremented to 2, ignoring for 10 seconds Feb 26 12:06:00 volumiofg dhcpcd[794]: wlan0: carrier lost Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=BE Feb 26 12:06:00 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_6B_A2_50_92_51_17/mcp/player0, ...) Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-SSID-REENABLED id=1 ssid="telenet-1117680" Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: Trying to associate with 38:43:7d:e7:48:78 (SSID='telenet-1117680' freq=5220 MHz) Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: Associated with 38:43:7d:e7:48:78 Feb 26 12:06:00 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 26 12:06:00 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 26 12:06:00 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 26 12:06:00 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 26 12:06:01 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:01 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:01 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:01 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:01 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:01 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:01 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:01 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:01 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:01 volumiofg volumio[3853]: info: BOOT COMPLETED Feb 26 12:06:01 volumiofg volumio[3853]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.096&uuid=282727c0c6316e08981f0fde705b817f" http://updates.volumio.org/downloader-v1/track-device Feb 26 12:06:01 volumiofg volumio[3853]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 26 12:06:01 volumiofg volumio[3853]: Dload Upload Total Spent Left Speed Feb 26 12:06:01 volumiofg volumio[3853]: [132B blob data] Feb 26 12:06:01 volumiofg volumio[3853]: retrying in 5 seconds, trial 2 Feb 26 12:06:01 volumiofg volumio[3853]: info: Volumio Calling Home Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-DISCONNECTED bssid=38:43:7d:e7:48:78 reason=15 Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=1 ssid="telenet-1117680" auth_failures=2 duration=33 reason=WRONG_KEY Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: BSSID 38:43:7d:e7:48:78 ignore list count incremented to 3, ignoring for 60 seconds Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=1 ssid="telenet-1117680" auth_failures=3 duration=42 reason=CONN_FAILED Feb 26 12:06:01 volumiofg dhcpcd[794]: wlan0: carrier lost Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Feb 26 12:06:01 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=BE Feb 26 12:06:01 volumiofg wireless.js[696]: WIRELESS.JS - INFO: WpaStateMachine: State transition: 4WAY_HANDSHAKE -> SCANNING (duration: 4056ms) Feb 26 12:06:01 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 26 12:06:01 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:02 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:02 volumiofg go-librespot[4749]: go-librespot daemon starting... Feb 26 12:06:02 volumiofg go-librespot[4750]: time="2026-02-26T12:06:02+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:02 volumiofg go-librespot[4750]: time="2026-02-26T12:06:02+01:00" level=debug msg="app state loaded" Feb 26 12:06:02 volumiofg go-librespot[4750]: time="2026-02-26T12:06:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:02 volumiofg go-librespot[4750]: time="2026-02-26T12:06:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:02 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:02 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:02 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:02 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:02 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:02 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:02 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:02 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:02 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:02 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:02 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:02 volumiofg dbus-daemon[677]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.17" (uid=0 pid=1708 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=825 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Feb 26 12:06:02 volumiofg bluetoothd[825]: Failed to disconnect device: Disconnected (0x0e) Feb 26 12:06:02 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:02 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:04 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:04 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:04 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:04 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:04 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:04 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:04 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:04 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:04 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:05 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 26 12:06:05 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:05 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:05 volumiofg go-librespot[4776]: go-librespot daemon starting... Feb 26 12:06:05 volumiofg go-librespot[4777]: time="2026-02-26T12:06:05+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:05 volumiofg go-librespot[4777]: time="2026-02-26T12:06:05+01:00" level=debug msg="app state loaded" Feb 26 12:06:05 volumiofg go-librespot[4777]: time="2026-02-26T12:06:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:05 volumiofg go-librespot[4777]: time="2026-02-26T12:06:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:05 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:05 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:05 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C, ...) Feb 26 12:06:05 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:05 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/mcp/player0, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0002, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0004, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0006, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0008, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014/char0015, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014/char0017, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014/char0019, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0029, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0029/desc002b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002c, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002c/desc002e, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002f, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002f/desc0031, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0032, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0032/desc0034, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0035, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0035/desc0037, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0038, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0038/desc003a, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003b/desc003d, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003e, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003e/desc0040, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0041, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0043, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0043/desc0045, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0046, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0046/desc0048, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0049, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0049/desc004b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char004c, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char005b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char005b/desc005d, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char005e, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0060, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0060/desc0062, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0063, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0063/desc0065, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0066, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0066/desc0068, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0069, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006b/desc006d, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006e, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006e/desc0070, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0071, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0071/desc0073, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0074, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0076, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0076/desc0078, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0079, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0079/desc007b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char007c, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char007c/desc007e, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0082, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0082/char0083, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0090, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0090/char0091, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0094, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0094/desc0096, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0097, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0097/desc0099, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service009a, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service009a/char009b, ...) Feb 26 12:06:06 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service009a/char009d, ...) Feb 26 12:06:07 volumiofg volumio5-onboarding[1708]: time=2026-02-26T12:06:07.973+01:00 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 Feb 26 12:06:08 volumiofg dbus-daemon[677]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.17" (uid=0 pid=1708 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=825 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Feb 26 12:06:08 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 26 12:06:08 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:08 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:08 volumiofg go-librespot[4817]: go-librespot daemon starting... Feb 26 12:06:08 volumiofg go-librespot[4821]: time="2026-02-26T12:06:08+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:08 volumiofg go-librespot[4821]: time="2026-02-26T12:06:08+01:00" level=debug msg="app state loaded" Feb 26 12:06:08 volumiofg go-librespot[4821]: time="2026-02-26T12:06:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:08 volumiofg go-librespot[4821]: time="2026-02-26T12:06:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:08 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:08 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:08 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:08 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:09 volumiofg nmbd[1093]: [2026/02/26 12:06:09.057410, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Feb 26 12:06:09 volumiofg nmbd[1093]: Packet send failed to 192.168.211.255(137) ERRNO=Network is unreachable Feb 26 12:06:09 volumiofg nmbd[1093]: [2026/02/26 12:06:09.057547, 0] ../../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Feb 26 12:06:09 volumiofg nmbd[1093]: send_netbios_packet: send_packet() to IP 192.168.211.255 port 137 failed Feb 26 12:06:09 volumiofg nmbd[1093]: [2026/02/26 12:06:09.057596, 0] ../../source3/nmbd/nmbd_namequery.c:245(query_name) Feb 26 12:06:09 volumiofg nmbd[1093]: query_name: Failed to send packet trying to query name WORKGROUP<1d> Feb 26 12:06:09 volumiofg ifplugd(eth0)[1062]: Executing '/etc/ifplugd/ifplugd.action eth0 down'. Feb 26 12:06:09 volumiofg ifplugd(eth0)[1062]: client: dhcpcd not running Feb 26 12:06:09 volumiofg dhcpcd[4846]: dhcpcd not running Feb 26 12:06:09 volumiofg ifplugd(eth0)[1062]: Program executed successfully. Feb 26 12:06:09 volumiofg kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Feb 26 12:06:09 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Down Feb 26 12:06:10 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/mcp/player0, ...) Feb 26 12:06:10 volumiofg dbus-daemon[677]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.17" (uid=0 pid=1708 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=825 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Feb 26 12:06:10 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:10 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:10 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:10 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:10 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:10 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:10 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:10 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:10 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:11 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 26 12:06:11 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:11 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:11 volumiofg go-librespot[4874]: go-librespot daemon starting... Feb 26 12:06:11 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:11 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:11 volumiofg go-librespot[4875]: time="2026-02-26T12:06:11+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:11 volumiofg go-librespot[4875]: time="2026-02-26T12:06:11+01:00" level=debug msg="app state loaded" Feb 26 12:06:11 volumiofg go-librespot[4875]: time="2026-02-26T12:06:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:11 volumiofg go-librespot[4875]: time="2026-02-26T12:06:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:11 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:11 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:14 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:14 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:14 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 26 12:06:14 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:15 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:15 volumiofg go-librespot[4902]: go-librespot daemon starting... Feb 26 12:06:15 volumiofg go-librespot[4903]: time="2026-02-26T12:06:15+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:15 volumiofg go-librespot[4903]: time="2026-02-26T12:06:15+01:00" level=debug msg="app state loaded" Feb 26 12:06:15 volumiofg go-librespot[4903]: time="2026-02-26T12:06:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:15 volumiofg go-librespot[4903]: time="2026-02-26T12:06:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:15 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:15 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:15 volumiofg bluetoothd[825]: io_glib_add_err_watch_full: assertion '!(events & (G_IO_IN | G_IO_OUT))' failed Feb 26 12:06:16 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03, ...) Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: WpaStateMachine: SCANNING timeout - network not found Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: STAGE 2: Connection failed - Network not found - check SSID and signal strength Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: STAGE 2: Failure details: Network not found after scanning Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: STAGE 2: Skipping afterAPStart loop, proceeding directly to hotspot evaluation Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: Start ap Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: STAGE 2: Connection already failed, skipping polling loop Feb 26 12:06:16 volumiofg wireless.js[696]: WIRELESS.JS - INFO: STAGE 2: Evaluating hotspot condition directly Feb 26 12:06:16 volumiofg sudo[4927]: root : unable to resolve host volumiofg: System error Feb 26 12:06:16 volumiofg sudo[4927]: root : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Feb 26 12:06:16 volumiofg sudo[4927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/mcp/player0, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0002, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0004, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0006, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0008, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014/char0015, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014/char0017, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014/char0019, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0029, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0029/desc002b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002c, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002c/desc002e, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002f, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002f/desc0031, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0032, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0032/desc0034, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0035, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0035/desc0037, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0038, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0038/desc003a, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003b/desc003d, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003e, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003e/desc0040, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0041, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0043, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0043/desc0045, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0046, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0046/desc0048, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0049, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0049/desc004b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char004c, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char005b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char005b/desc005d, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char005e, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0060, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0060/desc0062, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0063, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0063/desc0065, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0066, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0066/desc0068, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0069, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006b/desc006d, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006e, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006e/desc0070, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0071, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0071/desc0073, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0074, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0076, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0076/desc0078, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0079, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0079/desc007b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char007c, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char007c/desc007e, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0082, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0082/char0083, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0090, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0090/char0091, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0094, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0094/desc0096, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0097, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0097/desc0099, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service009a, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service009a/char009b, ...) Feb 26 12:06:17 volumiofg bluealsa[951]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_19_6D_63_62_03/service009a/char009d, ...) Feb 26 12:06:17 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:17 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:18 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 26 12:06:18 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:18 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:18 volumiofg go-librespot[4944]: go-librespot daemon starting... Feb 26 12:06:18 volumiofg go-librespot[4945]: time="2026-02-26T12:06:18+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:18 volumiofg go-librespot[4945]: time="2026-02-26T12:06:18+01:00" level=debug msg="app state loaded" Feb 26 12:06:18 volumiofg go-librespot[4945]: time="2026-02-26T12:06:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:18 volumiofg go-librespot[4945]: time="2026-02-26T12:06:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:18 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:18 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:18 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/mcp/player0, ...) Feb 26 12:06:19 volumiofg sudo[4927]: pam_unix(sudo:session): session closed for user root Feb 26 12:06:19 volumiofg wireless.js[696]: sudo: unable to resolve host volumiofg: System error Feb 26 12:06:19 volumiofg wireless.js[696]: WIRELESS.JS - INFO: No concurrent mode. Stopping STA and starting hotspot. Feb 26 12:06:19 volumiofg wireless.js[696]: WIRELESS.JS - INFO: Notified systemd about wireless ready Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Feb 26 12:06:19 volumiofg wpa_supplicant[4291]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Feb 26 12:06:20 volumiofg wpa_supplicant[4291]: wlan0: CTRL-EVENT-TERMINATING Feb 26 12:06:20 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:20 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:20 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:20 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:20 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:20 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:20 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:20 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:20 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:21 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 26 12:06:21 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:21 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:21 volumiofg go-librespot[4963]: go-librespot daemon starting... Feb 26 12:06:21 volumiofg go-librespot[4964]: time="2026-02-26T12:06:21+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:21 volumiofg go-librespot[4964]: time="2026-02-26T12:06:21+01:00" level=debug msg="app state loaded" Feb 26 12:06:21 volumiofg go-librespot[4964]: time="2026-02-26T12:06:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:21 volumiofg go-librespot[4964]: time="2026-02-26T12:06:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:21 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:21 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:22 volumiofg dhcpcd[794]: eth0: carrier acquired Feb 26 12:06:22 volumiofg dhcpcd[794]: eth0: IAID 01:f7:d1:ad Feb 26 12:06:22 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Feb 26 12:06:22 volumiofg dhcpcd[794]: eth0: rebinding lease of 192.168.0.219 Feb 26 12:06:22 volumiofg dhcpcd[794]: eth0: soliciting an IPv6 router Feb 26 12:06:22 volumiofg sudo[4978]: root : unable to resolve host volumiofg: System error Feb 26 12:06:22 volumiofg sudo[4978]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Feb 26 12:06:22 volumiofg sudo[4978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 12:06:22 volumiofg sudo[4978]: pam_unix(sudo:session): session closed for user root Feb 26 12:06:22 volumiofg sudo[4980]: root : unable to resolve host volumiofg: System error Feb 26 12:06:22 volumiofg sudo[4980]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Feb 26 12:06:22 volumiofg sudo[4980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 26 12:06:22 volumiofg sudo[4980]: pam_unix(sudo:session): session closed for user root Feb 26 12:06:22 volumiofg avahi-daemon[675]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Feb 26 12:06:22 volumiofg avahi-daemon[675]: New relevant interface wlan0.IPv4 for mDNS. Feb 26 12:06:22 volumiofg avahi-daemon[675]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Feb 26 12:06:22 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:22 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:22 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:22 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:22 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:22 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:22 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:22 volumiofg kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Feb 26 12:06:22 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:22 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:22 volumiofg ifplugd(eth0)[1062]: Link beat detected. Feb 26 12:06:22 volumiofg systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 26 12:06:22 volumiofg systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Feb 26 12:06:22 volumiofg systemd[1]: welcome.service: Deactivated successfully. Feb 26 12:06:22 volumiofg systemd[1]: Stopped welcome.service - Show a welcome message on console. Feb 26 12:06:22 volumiofg systemd[1]: Stopping welcome.service - Show a welcome message on console... Feb 26 12:06:22 volumiofg systemd[1]: Starting welcome.service - Show a welcome message on console... Feb 26 12:06:22 volumiofg wireless.js[696]: WIRELESS.JS - INFO: Notified systemd about wireless ready Feb 26 12:06:22 volumiofg welcome[4989]: Resolved ip:[1] 192.168.211.1 Feb 26 12:06:22 volumiofg ifplugd(eth0)[1062]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Feb 26 12:06:22 volumiofg systemd[1]: Starting hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... Feb 26 12:06:22 volumiofg systemd[1]: Finished welcome.service - Show a welcome message on console. Feb 26 12:06:22 volumiofg systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 26 12:06:22 volumiofg dhcpcd[794]: wlan0: carrier acquired Feb 26 12:06:22 volumiofg hostapd[4998]: wlan0: interface state UNINITIALIZED->ENABLED Feb 26 12:06:22 volumiofg hostapd[4998]: wlan0: AP-ENABLED Feb 26 12:06:22 volumiofg systemd[1]: Started hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Feb 26 12:06:22 volumiofg dhcpcd[794]: wlan0: IAID 01:f7:d1:ae Feb 26 12:06:22 volumiofg dhcpcd[794]: wlan0: soliciting an IPv6 router Feb 26 12:06:22 volumiofg dhcpcd[794]: ps_ctl_dispatch: cannot handle another client Feb 26 12:06:22 volumiofg ifplugd(eth0)[1062]: client: sending commands to dhcpcd process Feb 26 12:06:22 volumiofg dhcpcd[794]: control_free: No such file or directory Feb 26 12:06:22 volumiofg systemd[1]: Starting dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... Feb 26 12:06:23 volumiofg dnsmasq[5046]: started, version 2.90 cachesize 150 Feb 26 12:06:23 volumiofg dnsmasq[5046]: compile time options: IPv6 GNU-getopt DBus no-UBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth cryptohash DNSSEC loop-detect inotify dumpfile Feb 26 12:06:23 volumiofg dnsmasq-dhcp[5046]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Feb 26 12:06:23 volumiofg dnsmasq[5046]: reading /etc/resolv.conf Feb 26 12:06:23 volumiofg dnsmasq[5046]: using nameserver 208.67.222.222#53 Feb 26 12:06:23 volumiofg dnsmasq[5046]: using nameserver 208.67.220.220#53 Feb 26 12:06:23 volumiofg dnsmasq[5046]: read /etc/hosts - 4 names Feb 26 12:06:23 volumiofg systemd[1]: Started dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. Feb 26 12:06:23 volumiofg ifplugd(eth0)[1062]: Program executed successfully. Feb 26 12:06:23 volumiofg dhcpcd[794]: eth0: carrier lost Feb 26 12:06:23 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Down Feb 26 12:06:23 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:23 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:23 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:23 volumiofg volumio[3853]: info: Discovery: adding abf5be70-0287-402d-b8a5-d8538dae7137 Feb 26 12:06:23 volumiofg volumio[3853]: info: Discovery: Found device Volumio_fg Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:23 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:23 volumiofg systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 26 12:06:23 volumiofg systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Feb 26 12:06:23 volumiofg systemd[1]: welcome.service: Deactivated successfully. Feb 26 12:06:23 volumiofg systemd[1]: Stopped welcome.service - Show a welcome message on console. Feb 26 12:06:23 volumiofg systemd[1]: Stopping welcome.service - Show a welcome message on console... Feb 26 12:06:23 volumiofg systemd[1]: Starting welcome.service - Show a welcome message on console... Feb 26 12:06:23 volumiofg welcome[5071]: Resolved ip:[1] 192.168.211.1 Feb 26 12:06:23 volumiofg systemd[1]: Finished welcome.service - Show a welcome message on console. Feb 26 12:06:23 volumiofg systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Feb 26 12:06:23 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:23 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:23 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:23 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:23 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:23 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:24 volumiofg ifplugd(eth0)[1062]: Link beat lost. Feb 26 12:06:24 volumiofg dhcpcd[794]: wlan0: soliciting a DHCP lease Feb 26 12:06:24 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 26 12:06:24 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:24 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:24 volumiofg go-librespot[5077]: go-librespot daemon starting... Feb 26 12:06:24 volumiofg go-librespot[5078]: time="2026-02-26T12:06:24+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:24 volumiofg go-librespot[5078]: time="2026-02-26T12:06:24+01:00" level=debug msg="app state loaded" Feb 26 12:06:24 volumiofg go-librespot[5078]: time="2026-02-26T12:06:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:24 volumiofg go-librespot[5078]: time="2026-02-26T12:06:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:24 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:24 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:25 volumiofg ntpd[1057]: IO: Listen normally on 8 wlan0 192.168.211.1:123 Feb 26 12:06:25 volumiofg ntpd[1057]: IO: new interface(s) found: waking up resolver Feb 26 12:06:26 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:26 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:27 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 26 12:06:27 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:28 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:28 volumiofg go-librespot[5100]: go-librespot daemon starting... Feb 26 12:06:28 volumiofg go-librespot[5101]: time="2026-02-26T12:06:28+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:28 volumiofg go-librespot[5101]: time="2026-02-26T12:06:28+01:00" level=debug msg="app state loaded" Feb 26 12:06:28 volumiofg go-librespot[5101]: time="2026-02-26T12:06:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:28 volumiofg go-librespot[5101]: time="2026-02-26T12:06:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:28 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:28 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:29 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:29 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:31 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 26 12:06:31 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:31 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:31 volumiofg go-librespot[5110]: go-librespot daemon starting... Feb 26 12:06:31 volumiofg go-librespot[5111]: time="2026-02-26T12:06:31+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:31 volumiofg go-librespot[5111]: time="2026-02-26T12:06:31+01:00" level=debug msg="app state loaded" Feb 26 12:06:31 volumiofg go-librespot[5111]: time="2026-02-26T12:06:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:31 volumiofg go-librespot[5111]: time="2026-02-26T12:06:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:31 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:31 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:32 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:32 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:34 volumiofg ifplugd(eth0)[1062]: Executing '/etc/ifplugd/ifplugd.action eth0 down'. Feb 26 12:06:34 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 26 12:06:34 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:34 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:34 volumiofg go-librespot[5127]: go-librespot daemon starting... Feb 26 12:06:34 volumiofg dhcpcd[5136]: dhcpcd not running Feb 26 12:06:34 volumiofg ifplugd(eth0)[1062]: client: dhcpcd not running Feb 26 12:06:34 volumiofg go-librespot[5128]: time="2026-02-26T12:06:34+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:34 volumiofg go-librespot[5128]: time="2026-02-26T12:06:34+01:00" level=debug msg="app state loaded" Feb 26 12:06:34 volumiofg go-librespot[5128]: time="2026-02-26T12:06:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:34 volumiofg go-librespot[5128]: time="2026-02-26T12:06:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:34 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:34 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:34 volumiofg ifplugd(eth0)[1062]: Program executed successfully. Feb 26 12:06:34 volumiofg kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Feb 26 12:06:34 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Down Feb 26 12:06:35 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:35 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:35 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:35 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:35 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:35 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:35 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:35 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:35 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:35 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:35 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:37 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 26 12:06:37 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:37 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:37 volumiofg go-librespot[5151]: go-librespot daemon starting... Feb 26 12:06:37 volumiofg go-librespot[5152]: time="2026-02-26T12:06:37+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:37 volumiofg go-librespot[5152]: time="2026-02-26T12:06:37+01:00" level=debug msg="app state loaded" Feb 26 12:06:37 volumiofg go-librespot[5152]: time="2026-02-26T12:06:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:37 volumiofg go-librespot[5152]: time="2026-02-26T12:06:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:37 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:37 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:38 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:38 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0002, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0004, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0006, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001/char0008, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0001, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014/char0015, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014/char0017, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014/char0019, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0014, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0029/desc002b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0029, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002c/desc002e, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002c, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002f/desc0031, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char002f, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0032/desc0034, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0032, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0035/desc0037, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0035, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0038/desc003a, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0038, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003b/desc003d, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003e/desc0040, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char003e, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0041, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0043/desc0045, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0043, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0046/desc0048, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0046, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0049/desc004b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char0049, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028/char004c, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0028, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char005b/desc005d, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char005b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char005e, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0060/desc0062, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0060, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0063/desc0065, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0063, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0066/desc0068, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0066, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0069, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006b/desc006d, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006e/desc0070, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char006e, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0071/desc0073, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0071, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0074, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0076/desc0078, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0076, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0079/desc007b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char0079, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char007c/desc007e, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a/char007c, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service005a, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0082/char0083, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0082, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0090/char0091, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0090, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0094/desc0096, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0094, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0097/desc0099, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093/char0097, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service0093, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service009a/char009b, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service009a/char009d, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C/service009a, ...) Feb 26 12:06:40 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_13_5F_B8_1C_2C, ...) Feb 26 12:06:40 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 26 12:06:40 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:40 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:40 volumiofg go-librespot[5174]: go-librespot daemon starting... Feb 26 12:06:40 volumiofg go-librespot[5175]: time="2026-02-26T12:06:40+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:40 volumiofg go-librespot[5175]: time="2026-02-26T12:06:40+01:00" level=debug msg="app state loaded" Feb 26 12:06:40 volumiofg go-librespot[5175]: time="2026-02-26T12:06:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:40 volumiofg go-librespot[5175]: time="2026-02-26T12:06:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:40 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:40 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:41 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:41 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:43 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 26 12:06:43 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:44 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:44 volumiofg go-librespot[5183]: go-librespot daemon starting... Feb 26 12:06:44 volumiofg go-librespot[5184]: time="2026-02-26T12:06:44+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:44 volumiofg go-librespot[5184]: time="2026-02-26T12:06:44+01:00" level=debug msg="app state loaded" Feb 26 12:06:44 volumiofg go-librespot[5184]: time="2026-02-26T12:06:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:44 volumiofg go-librespot[5184]: time="2026-02-26T12:06:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:44 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:44 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:44 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:44 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:47 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 26 12:06:47 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:47 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:47 volumiofg go-librespot[5192]: go-librespot daemon starting... Feb 26 12:06:47 volumiofg go-librespot[5193]: time="2026-02-26T12:06:47+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:47 volumiofg go-librespot[5193]: time="2026-02-26T12:06:47+01:00" level=debug msg="app state loaded" Feb 26 12:06:47 volumiofg go-librespot[5193]: time="2026-02-26T12:06:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:47 volumiofg go-librespot[5193]: time="2026-02-26T12:06:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:47 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:47 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:47 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:47 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0002, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0004, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0006, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001/char0008, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0001, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014/char0015, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014/char0017, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014/char0019, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0014, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0029/desc002b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0029, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002c/desc002e, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002c, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002f/desc0031, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char002f, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0032/desc0034, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0032, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0035/desc0037, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0035, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0038/desc003a, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0038, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003b/desc003d, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003e/desc0040, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char003e, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0041, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0043/desc0045, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0043, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0046/desc0048, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0046, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0049/desc004b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char0049, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028/char004c, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0028, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char005b/desc005d, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char005b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char005e, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0060/desc0062, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0060, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0063/desc0065, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0063, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0066/desc0068, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0066, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0069, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006b/desc006d, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006e/desc0070, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char006e, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0071/desc0073, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0071, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0074, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0076/desc0078, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0076, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0079/desc007b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char0079, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char007c/desc007e, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a/char007c, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service005a, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0082/char0083, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0082, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0090/char0091, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0090, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0094/desc0096, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0094, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0097/desc0099, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093/char0097, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service0093, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service009a/char009b, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service009a/char009d, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03/service009a, ...) Feb 26 12:06:48 volumiofg bluealsa[951]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_19_6D_63_62_03, ...) Feb 26 12:06:50 volumiofg dhcpcd[794]: eth0: carrier acquired Feb 26 12:06:50 volumiofg dhcpcd[794]: eth0: IAID 01:f7:d1:ad Feb 26 12:06:50 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Feb 26 12:06:50 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 26 12:06:50 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:50 volumiofg dhcpcd[794]: eth0: soliciting an IPv6 router Feb 26 12:06:50 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:50 volumiofg go-librespot[5217]: go-librespot daemon starting... Feb 26 12:06:50 volumiofg go-librespot[5218]: time="2026-02-26T12:06:50+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:50 volumiofg go-librespot[5218]: time="2026-02-26T12:06:50+01:00" level=debug msg="app state loaded" Feb 26 12:06:50 volumiofg go-librespot[5218]: time="2026-02-26T12:06:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:50 volumiofg dhcpcd[794]: eth0: soliciting a DHCP lease Feb 26 12:06:50 volumiofg go-librespot[5218]: time="2026-02-26T12:06:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:50 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:50 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:50 volumiofg ifplugd(eth0)[1062]: Link beat detected. Feb 26 12:06:50 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:50 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:50 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:50 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:50 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:50 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:50 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:50 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:50 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:50 volumiofg ifplugd(eth0)[1062]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Feb 26 12:06:50 volumiofg dhcpcd[794]: ps_ctl_dispatch: cannot handle another client Feb 26 12:06:50 volumiofg ifplugd(eth0)[1062]: client: sending commands to dhcpcd process Feb 26 12:06:50 volumiofg dhcpcd[794]: control_free: No such file or directory Feb 26 12:06:50 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:50 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:50 volumiofg ifplugd(eth0)[1062]: Program executed successfully. Feb 26 12:06:51 volumiofg dhcpcd[794]: eth0: carrier lost Feb 26 12:06:51 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Down Feb 26 12:06:51 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:51 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:51 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:51 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:51 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:51 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:51 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:51 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:51 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:51 volumiofg ifplugd(eth0)[1062]: Link beat lost. Feb 26 12:06:53 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 26 12:06:53 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:53 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:53 volumiofg go-librespot[5290]: go-librespot daemon starting... Feb 26 12:06:53 volumiofg go-librespot[5291]: time="2026-02-26T12:06:53+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:53 volumiofg go-librespot[5291]: time="2026-02-26T12:06:53+01:00" level=debug msg="app state loaded" Feb 26 12:06:53 volumiofg go-librespot[5291]: time="2026-02-26T12:06:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:53 volumiofg go-librespot[5291]: time="2026-02-26T12:06:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:53 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:53 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:53 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:53 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:56 volumiofg dhcpcd[794]: eth0: carrier acquired Feb 26 12:06:56 volumiofg dhcpcd[794]: eth0: IAID 01:f7:d1:ad Feb 26 12:06:56 volumiofg kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Feb 26 12:06:56 volumiofg dhcpcd[794]: eth0: soliciting an IPv6 router Feb 26 12:06:56 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:56 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:06:56 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:06:56 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:06:56 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:06:56 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:06:56 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:06:56 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:06:56 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:06:56 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:06:56 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:06:56 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 26 12:06:56 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:57 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:06:57 volumiofg go-librespot[5300]: go-librespot daemon starting... Feb 26 12:06:57 volumiofg go-librespot[5301]: time="2026-02-26T12:06:57+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:06:57 volumiofg go-librespot[5301]: time="2026-02-26T12:06:57+01:00" level=debug msg="app state loaded" Feb 26 12:06:57 volumiofg go-librespot[5301]: time="2026-02-26T12:06:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:06:57 volumiofg go-librespot[5301]: time="2026-02-26T12:06:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:06:57 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:06:57 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:06:57 volumiofg ifplugd(eth0)[1062]: Link beat detected. Feb 26 12:06:57 volumiofg dhcpcd[794]: eth0: soliciting a DHCP lease Feb 26 12:06:58 volumiofg dhcpcd[794]: eth0: offered 192.168.0.219 from 192.168.0.1 Feb 26 12:06:58 volumiofg dhcpcd[794]: eth0: probing address 192.168.0.219/24 Feb 26 12:06:59 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:06:59 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:07:00 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 26 12:07:00 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:07:00 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:07:00 volumiofg go-librespot[5325]: go-librespot daemon starting... Feb 26 12:07:00 volumiofg go-librespot[5326]: time="2026-02-26T12:07:00+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:07:00 volumiofg go-librespot[5326]: time="2026-02-26T12:07:00+01:00" level=debug msg="app state loaded" Feb 26 12:07:00 volumiofg go-librespot[5326]: time="2026-02-26T12:07:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:07:00 volumiofg go-librespot[5326]: time="2026-02-26T12:07:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 26 12:07:00 volumiofg systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 26 12:07:00 volumiofg systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 26 12:07:02 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:07:02 volumiofg volumio[3853]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 26 12:07:03 volumiofg dhcpcd[794]: eth0: leased 192.168.0.219 for 3600 seconds Feb 26 12:07:03 volumiofg avahi-daemon[675]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.219. Feb 26 12:07:03 volumiofg avahi-daemon[675]: New relevant interface eth0.IPv4 for mDNS. Feb 26 12:07:03 volumiofg avahi-daemon[675]: Registering new address record for 192.168.0.219 on eth0.IPv4. Feb 26 12:07:03 volumiofg dhcpcd[794]: eth0: adding route to 192.168.0.0/24 Feb 26 12:07:03 volumiofg systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Feb 26 12:07:03 volumiofg systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Feb 26 12:07:03 volumiofg systemd[1]: welcome.service: Deactivated successfully. Feb 26 12:07:03 volumiofg systemd[1]: Stopped welcome.service - Show a welcome message on console. Feb 26 12:07:03 volumiofg systemd[1]: Stopping welcome.service - Show a welcome message on console... Feb 26 12:07:03 volumiofg dnsmasq[5046]: reading /etc/resolv.conf Feb 26 12:07:03 volumiofg dnsmasq[5046]: using nameserver 195.130.131.4#53 Feb 26 12:07:03 volumiofg dnsmasq[5046]: using nameserver 195.130.130.4#53 Feb 26 12:07:03 volumiofg dnsmasq[5046]: using nameserver 208.67.222.222#53 Feb 26 12:07:03 volumiofg dnsmasq[5046]: using nameserver 208.67.220.220#53 Feb 26 12:07:03 volumiofg dhcpcd[794]: eth0: adding default route via 192.168.0.1 Feb 26 12:07:03 volumiofg systemd[1]: Starting welcome.service - Show a welcome message on console... Feb 26 12:07:03 volumiofg welcome[5351]: Resolved ip:[2] 192.168.0.219 192.168.211.1 Feb 26 12:07:03 volumiofg systemd[1]: Finished welcome.service - Show a welcome message on console. Feb 26 12:07:03 volumiofg systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Feb 26 12:07:03 volumiofg volumio5-onboarding[1708]: time=2026-02-26T12:07:03.371+01:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.0.113:46892 error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 26 12:07:03 volumiofg volumio5-onboarding[1708]: time=2026-02-26T12:07:03.371+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.0.113:46892 Feb 26 12:07:03 volumiofg volumio5-onboarding[1708]: time=2026-02-26T12:07:03.371+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.0.113:46892 Feb 26 12:07:03 volumiofg systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 26 12:07:03 volumiofg systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:07:03 volumiofg systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 26 12:07:03 volumiofg go-librespot[5361]: go-librespot daemon starting... Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=info msg="running go-librespot 0.6.2" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="app state loaded" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 26 12:07:03 volumiofg volumio[3853]: info: Received Get System Info Feb 26 12:07:03 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 26 12:07:03 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 26 12:07:03 volumiofg volumio[3853]: info: Discovery: Getting this device information Feb 26 12:07:03 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:07:03 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:07:03 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 26 12:07:03 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 26 12:07:03 volumiofg volumio[3853]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 26 12:07:03 volumiofg volumio5-onboarding[1708]: time=2026-02-26T12:07:03.674+01:00 level=INFO msg="disabling BLE discovery" Feb 26 12:07:03 volumiofg volumio5-onboarding[1708]: time=2026-02-26T12:07:03.680+01:00 level=INFO msg="connection closed, stopping read loop" component=conn/multi net=ble addr=E4:5F:01:F7:D1:AF%00 Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=info msg="zeroconf server listening on port 41467" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="obtained new client token: AACYVV8myVDxPedWQcEj0dpFO8IsQ4GuphFi10rDqwJB/4hKg4Xo+jHxBGu3tT8Di51I42tnzS1+u8jb3dK4GBRl+/vRQHmwnIg1Mp5mzcg7IXQrkTGQvIm+2QyVFKzfgVyufw5GzhvfC2BEh806Y4DkMuIesTcH9wU5E1wvr5+P4+FZL/+p1TL2EXo7DmJEe4SQ9Y2X0BrCbAtGeNcrGZNZTSR/6+UBAU/QZOdRE75tyLt21taB7nM=" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="completed keyexchange" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=debug msg="completed challenge" Feb 26 12:07:03 volumiofg go-librespot[5362]: time="2026-02-26T12:07:03+01:00" level=info msg="authenticated AP" username="21*********************hi" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=info msg="authenticated Login5" username="21*********************hi" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="initializing zeroconf session" username="21*********************hi" Feb 26 12:07:04 volumiofg volumio[3853]: info: Discovery: this is already registered, abf5be70-0287-402d-b8a5-d8538dae7137 Feb 26 12:07:04 volumiofg volumio[3853]: info: Discovery: Found device Volumio_fg Feb 26 12:07:04 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:07:04 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="dealer connection opened" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=trace msg="starting accesspoint recv loop" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=trace msg="starting dealer recv loop" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=trace msg="received accesspoint ping" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="received connection id: YjQzNDAxOGItMTA2...RjUxOTA5RjEwRQ==" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=trace msg="received accesspoint pong ack" Feb 26 12:07:04 volumiofg go-librespot[5362]: time="2026-02-26T12:07:04+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 26 12:07:05 volumiofg ntpd[1057]: IO: Listen normally on 9 eth0 192.168.0.219:123 Feb 26 12:07:05 volumiofg ntpd[1057]: IO: new interface(s) found: waking up resolver Feb 26 12:07:05 volumiofg volumio[3853]: info: Initializing connection to go-librespot Websocket Feb 26 12:07:05 volumiofg go-librespot[5362]: time="2026-02-26T12:07:05+01:00" level=debug msg="new websocket client" Feb 26 12:07:05 volumiofg volumio[3853]: info: Connection to go-librespot Websocket established Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="handling transfer player command from 8134ea88903edd84c8c4df9481fcb25e115cce3b" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E4wtCcs9vnp6h" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E4wtCcs9vnp6h" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="loading track (paused: true, position: 247143ms)" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=trace msg="emitting websocket event: will_play" Feb 26 12:07:06 volumiofg volumio[3853]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E4wtCcs9vnp6h","uri":"spotify:track:2W1wZG52PIlXihmHnNXE1G","play_origin":"playlist"}} Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="selected format OGG_VORBIS_320 (3768d64ca09f573fe761e3cee9abb78dcdd4524b)" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="requested aes key for file 3768d64ca09f573fe761e3cee9abb78dcdd4524b, gid: 2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched first chunk of 25, total size is 12907200 bytes" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 17/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 20/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 18/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=trace msg="seek to 247143ms (diff: 207ms, samples: 10899006, bytes: 9433611)" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="created new output device" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=info msg="loaded track \"Creole\" (paused: true, position: 247143ms, duration: 342400ms, prefetched: false)" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 19/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=trace msg="emitting websocket event: metadata" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=trace msg="emitting websocket event: active" Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="sending successful reply for dealer request" Feb 26 12:07:06 volumiofg volumio[3853]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2W1wZG52PIlXihmHnNXE1G","name":"Creole","artist_names":["Charlie Hunter","Mos Def"],"album_name":"Songs From The Analog Playground","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a0346b4f74fada4b0afb6dc2","position":247143,"duration":342400,"release_date":"year:2001 month:1 day:1","track_number":11,"disc_number":1}} Feb 26 12:07:06 volumiofg volumio[3853]: SPOTIFY: received: {"type":"active","data":null} Feb 26 12:07:06 volumiofg volumio[3853]: info: Aligning Spotify Volume to Volumio Volume Feb 26 12:07:06 volumiofg volumio[3853]: info: CoreCommandRouter::volumioGetState Feb 26 12:07:06 volumiofg volumio[3853]: info: CorePlayQueue::getTrack 0 Feb 26 12:07:06 volumiofg volumio[3853]: info: Setting Spotify Volume from Volumio: 65 Feb 26 12:07:06 volumiofg go-librespot[5362]: time="2026-02-26T12:07:06+01:00" level=debug msg="fetched chunk 21/24, size: 524288" uri="spotify:track:2W1wZG52PIlXihmHnNXE1G" Feb 26 12:07:07 volumiofg go-librespot[5362]: time="2026-02-26T12:07:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 12:07:07 volumiofg go-librespot[5362]: time="2026-02-26T12:07:07+01:00" level=trace msg="emitting websocket event: paused" Feb 26 12:07:07 volumiofg volumio[3853]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:37i9dQZF1E4wtCcs9vnp6h","uri":"spotify:track:2W1wZG52PIlXihmHnNXE1G","play_origin":"playlist"}} Feb 26 12:07:07 volumiofg volumio[3853]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 12:07:07 volumiofg volumio[3853]: TypeError: Cannot read properties of undefined (reading 'service') Feb 26 12:07:07 volumiofg volumio[3853]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Feb 26 12:07:07 volumiofg volumio[3853]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Feb 26 12:07:07 volumiofg volumio[3853]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Feb 26 12:07:07 volumiofg volumio[3853]: at WebSocket.emit (node:events:514:28) Feb 26 12:07:07 volumiofg volumio[3853]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 26 12:07:07 volumiofg volumio[3853]: at Receiver.emit (node:events:514:28) Feb 26 12:07:07 volumiofg volumio[3853]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 26 12:07:07 volumiofg volumio[3853]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 26 12:07:07 volumiofg volumio[3853]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 26 12:07:07 volumiofg volumio[3853]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 26 12:07:07 volumiofg volumio[3853]: at writeOrBuffer (node:internal/streams/writable:399:12) Feb 26 12:07:07 volumiofg volumio[3853]: at _write (node:internal/streams/writable:340:10) Feb 26 12:07:07 volumiofg volumio[3853]: at Writable.write (node:internal/streams/writable:344:10) Feb 26 12:07:07 volumiofg volumio[3853]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 26 12:07:07 volumiofg volumio[3853]: at Socket.emit (node:events:514:28) Feb 26 12:07:07 volumiofg volumio[3853]: at addChunk (node:internal/streams/readable:343:12) Feb 26 12:07:07 volumiofg volumio[3853]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 12:07:07 volumiofg sudo[5386]: volumio : unable to resolve host volumiofg: System error Feb 26 12:07:07 volumiofg sudo[5386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 12:06' Feb 26 12:07:07 volumiofg sudo[5386]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"