Oct 14 15:32:00 ap4 bluetoothd[805]: Bluetooth daemon 5.83 Oct 14 15:32:00 ap4 systemd[1]: Started bluetooth.service - Bluetooth service. Oct 14 15:32:00 ap4 bluetoothd[805]: Starting SDP server Oct 14 15:32:00 ap4 bluetoothd[805]: Excluding (cli) sap Oct 14 15:32:00 ap4 bluetoothd[805]: Excluding (cli) scanparam Oct 14 15:32:00 ap4 bluetoothd[805]: Excluding (cli) midi Oct 14 15:32:00 ap4 bluetoothd[805]: Excluding (cli) battery Oct 14 15:32:00 ap4 avahi-daemon[659]: Service "AP4" (/services/volumio.service) successfully established. Oct 14 15:32:00 ap4 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Oct 14 15:32:00 ap4 kernel: Bluetooth: BNEP filters: protocol multicast Oct 14 15:32:00 ap4 kernel: Bluetooth: BNEP socket layer initialized Oct 14 15:32:00 ap4 bluetoothd[805]: Bluetooth management interface 1.23 initialized Oct 14 15:32:00 ap4 dbus-daemon[660]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=805 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Oct 14 15:32:00 ap4 bluetoothd[805]: Battery Provider Manager created Oct 14 15:32:00 ap4 kernel: Bluetooth: MGMT ver 1.23 Oct 14 15:32:00 ap4 systemd[1]: Starting bluealsa.service - BlueALSA service... Oct 14 15:32:00 ap4 kernel: NET: Registered PF_ALG protocol family Oct 14 15:32:00 ap4 kernel: cryptd: max_cpu_qlen set to 1000 Oct 14 15:32:00 ap4 ifup[816]: ifup: waiting for lock on /run/network/ifstate.wlan0 Oct 14 15:32:00 ap4 sh[913]: wlan0=wlan0 Oct 14 15:32:00 ap4 systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Oct 14 15:32:00 ap4 bluetoothd[805]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled Oct 14 15:32:00 ap4 bluetoothd[805]: bap: Operation not supported (95) Oct 14 15:32:00 ap4 bluetoothd[805]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16 Oct 14 15:32:00 ap4 systemd[1]: Finished networking.service - Raise network interfaces. Oct 14 15:32:00 ap4 systemd[1]: Reached target network.target - Network. Oct 14 15:32:00 ap4 systemd[1]: Reached target network-online.target - Network is Online. Oct 14 15:32:00 ap4 systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically... Oct 14 15:32:00 ap4 systemd[1]: Starting nmbd.service - Samba NMB Daemon... Oct 14 15:32:00 ap4 systemd[1]: Starting ntpsec.service - Network Time Service... Oct 14 15:32:00 ap4 systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... Oct 14 15:32:00 ap4 systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart... Oct 14 15:32:00 ap4 systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon... Oct 14 15:32:00 ap4 sm-notify[949]: Version 2.6.2 starting Oct 14 15:32:00 ap4 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 14 15:32:00 ap4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:32:00 ap4 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Oct 14 15:32:00 ap4 systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor. Oct 14 15:32:00 ap4 systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 14 15:32:00 ap4 systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. Oct 14 15:32:00 ap4 systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart. Oct 14 15:32:00 ap4 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Oct 14 15:32:00 ap4 welcome[958]: Resolved ip:[0] Oct 14 15:32:00 ap4 ntpd[959]: INIT: ntpd ntpsec-1.2.2: Starting Oct 14 15:32:00 ap4 ntp-systemd-wrapper[959]: 2026-10-14T15:32:00 ntpd[959]: INIT: ntpd ntpsec-1.2.2: Starting Oct 14 15:32:00 ap4 ntp-systemd-wrapper[959]: 2026-10-14T15:32:00 ntpd[959]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Oct 14 15:32:00 ap4 ntpd[959]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Oct 14 15:32:00 ap4 dbus-daemon[660]: [system] Successfully activated service 'org.freedesktop.hostname1' Oct 14 15:32:00 ap4 systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... Oct 14 15:32:00 ap4 systemd[1]: Started ntpsec.service - Network Time Service. Oct 14 15:32:00 ap4 systemd[1]: Started systemd-hostnamed.service - Hostname Service. Oct 14 15:32:01 ap4 ntpd[972]: INIT: precision = 0.833 usec (-20) Oct 14 15:32:01 ap4 ntpd[972]: INIT: successfully locked into RAM Oct 14 15:32:01 ap4 ifplugd(eth0)[988]: ifplugd 0.28 initializing. Oct 14 15:32:01 ap4 ifplugd(eth0)[988]: Using interface eth0/B8:27:EB:E2:A4:EB with driver (version: 6.12.74-v7+) Oct 14 15:32:01 ap4 ifplugd(eth0)[988]: Using detection mode: SIOCETHTOOL Oct 14 15:32:01 ap4 ifplugd(eth0)[988]: Initialization complete, link beat not detected. Oct 14 15:32:01 ap4 systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 14 15:32:01 ap4 ntpd[972]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf Oct 14 15:32:01 ap4 ntpd[972]: CONFIG: restrict nopeer ignored Oct 14 15:32:01 ap4 ntpd[972]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 14 15:32:01 ap4 ntpd[972]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2026-06-28T00:00Z last=2017-01-01T00:00Z ofs=37 Oct 14 15:32:01 ap4 ntpd[972]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 109 days ago Oct 14 15:32:01 ap4 ntpd[972]: INIT: Using SO_TIMESTAMPNS(ns) Oct 14 15:32:01 ap4 ntpd[972]: IO: Listen and drop on 0 v6wildcard [::]:123 Oct 14 15:32:01 ap4 ntpd[972]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 14 15:32:01 ap4 ntpd[972]: IO: Listen normally on 2 lo 127.0.0.1:123 Oct 14 15:32:01 ap4 ntpd[972]: IO: Listening on routing socket on fd #19 for interface updates Oct 14 15:32:01 ap4 ifplugd[942]: Network Interface Plugging Daemon...start eth0...done. Oct 14 15:32:01 ap4 systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Oct 14 15:32:01 ap4 ntpd[972]: INIT: This system has a 32-bit time_t. Oct 14 15:32:01 ap4 ntpd[972]: INIT: This ntpd will fail on 2038-01-19T03:14:07Z. Oct 14 15:32:01 ap4 ntpd[972]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 14 15:32:01 ap4 ntpd[972]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090 Oct 14 15:32:01 ap4 ntpd[972]: INIT: Running with OpenSSL 3.0.19 27 Jan 2026, 30000130 Oct 14 15:32:01 ap4 ntpd[972]: NTSc: Using system default root certificates. Oct 14 15:32:01 ap4 ntpd[972]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory Oct 14 15:32:02 ap4 bluealsa[890]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa Oct 14 15:32:02 ap4 bluealsa[890]: main.c:663: Starting main dispatching loop Oct 14 15:32:02 ap4 systemd[1]: Started bluealsa.service - BlueALSA service. Oct 14 15:32:02 ap4 bluealsa[890]: main.c:118: Acquired D-Bus service name: org.bluealsa Oct 14 15:32:02 ap4 bluealsa[890]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa Oct 14 15:32:02 ap4 systemd[1]: Reached target bluetooth.target - Bluetooth Support. Oct 14 15:32:02 ap4 bluealsa[890]: bluez.c:153: Registering media application: /org/bluez/hci0 Oct 14 15:32:02 ap4 bluealsa[890]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1 Oct 14 15:32:02 ap4 bluealsa[890]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2 Oct 14 15:32:02 ap4 bluealsa[890]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1 Oct 14 15:32:02 ap4 bluealsa[890]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2 Oct 14 15:32:02 ap4 bluetoothd[805]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/1 Oct 14 15:32:02 ap4 bluetoothd[805]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/2 Oct 14 15:32:02 ap4 bluetoothd[805]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/2 Oct 14 15:32:02 ap4 bluetoothd[805]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/1 Oct 14 15:32:02 ap4 ntpd[972]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:02 ap4 ntpd[972]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 14 15:32:02 ap4 ntpd[972]: DNS: dns_check: DNS error: -11, System error Oct 14 15:32:02 ap4 ntpd[972]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Oct 14 15:32:03 ap4 systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Oct 14 15:32:03 ap4 systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Oct 14 15:32:03 ap4 ntpd[972]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:03 ap4 ntpd[972]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 14 15:32:03 ap4 ntpd[972]: DNS: dns_check: DNS error: -11, System error Oct 14 15:32:03 ap4 ntpd[972]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Oct 14 15:32:03 ap4 nmbd[1018]: [2026/10/14 15:32:03.715914, 0] ../../source3/nmbd/nmbd.c:901(main) Oct 14 15:32:03 ap4 nmbd[1018]: nmbd version 4.17.8-Raspbian started. Oct 14 15:32:03 ap4 nmbd[1018]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 14 15:32:03 ap4 nmbd[1018]: [2026/10/14 15:32:03.721794, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Oct 14 15:32:03 ap4 nmbd[1018]: started asyncdns process 1021 Oct 14 15:32:03 ap4 nmbd[1018]: [2026/10/14 15:32:03.723211, 0] ../../lib/util/become_daemon.c:150(daemon_status) Oct 14 15:32:03 ap4 nmbd[1018]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Oct 14 15:32:03 ap4 nmbd[1018]: [2026/10/14 15:32:03.723347, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Oct 14 15:32:03 ap4 nmbd[1018]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Oct 14 15:32:04 ap4 wireless.js[689]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Oct 14 15:32:04 ap4 wireless.js[689]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Oct 14 15:32:04 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:04] [info] asio async_connect error: asio.system:111 (Connection refused) Oct 14 15:32:04 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:04] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Oct 14 15:32:04 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:04] [error] handle_connect error: Connection refused Oct 14 15:32:04 ap4 systemd[1]: systemd-rfkill.service: Deactivated successfully. Oct 14 15:32:04 ap4 sudo[1041]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 14 15:32:04 ap4 sudo[1041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:04 ap4 sudo[1041]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:04 ap4 sudo[1043]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 14 15:32:04 ap4 sudo[1043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:04 ap4 ntpd[972]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:04 ap4 ntpd[972]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 14 15:32:04 ap4 ntpd[972]: DNS: dns_check: DNS error: -11, System error Oct 14 15:32:04 ap4 ntpd[972]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Oct 14 15:32:05 ap4 sudo[1043]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: Cleaning previous... Oct 14 15:32:05 ap4 sudo[1053]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 14 15:32:05 ap4 sudo[1053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:05 ap4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 14 15:32:05 ap4 sudo[1053]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 3ms Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: b8:27:eb:b7:f1:be) Oct 14 15:32:05 ap4 sudo[1060]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 14 15:32:05 ap4 sudo[1060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:05 ap4 sudo[1060]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:05 ap4 sudo[1068]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 14 15:32:05 ap4 sudo[1068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:05 ap4 ntpd[972]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:05 ap4 ntpd[972]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 14 15:32:05 ap4 ntpd[972]: DNS: dns_check: DNS error: -11, System error Oct 14 15:32:05 ap4 ntpd[972]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Oct 14 15:32:05 ap4 sudo[1068]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: SETTING APPROPRIATE REG DOMAIN: KR Oct 14 15:32:05 ap4 sudo[1075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set KR Oct 14 15:32:05 ap4 sudo[1075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:05 ap4 sudo[1075]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: SUCCESSFULLY SET NEW REGDOMAIN: KR Oct 14 15:32:05 ap4 wireless.js[689]: WIRELESS.JS - INFO: Start wireless flow Oct 14 15:32:06 ap4 wireless.js[689]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Oct 14 15:32:06 ap4 sudo[1088]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 14 15:32:06 ap4 sudo[1088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:06 ap4 sudo[1088]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:06 ap4 sudo[1091]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 14 15:32:06 ap4 sudo[1091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:06 ap4 sudo[1091]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:06 ap4 wireless.js[689]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Oct 14 15:32:06 ap4 wireless.js[689]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: b8:27:eb:b7:f1:be, USB: false) Oct 14 15:32:06 ap4 wpa_supplicant[1097]: Successfully initialized wpa_supplicant Oct 14 15:32:06 ap4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 14 15:32:07 ap4 sudo[1109]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 14 15:32:07 ap4 sudo[1109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:07 ap4 sudo[1109]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:07 ap4 wpa_supplicant[1106]: wlan0: Trying to associate with e8:9c:25:15:54:68 (SSID='ministar' freq=2417 MHz) Oct 14 15:32:07 ap4 wpa_supplicant[1106]: wlan0: Associated with e8:9c:25:15:54:68 Oct 14 15:32:07 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 14 15:32:07 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CN Oct 14 15:32:07 ap4 wpa_supplicant[1106]: wlan0: WPA: Key negotiation completed with e8:9c:25:15:54:68 [PTK=CCMP GTK=CCMP] Oct 14 15:32:07 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-CONNECTED - Connection to e8:9c:25:15:54:68 completed [id=0 id_str=] Oct 14 15:32:07 ap4 dhcpcd[749]: wlan0: carrier acquired Oct 14 15:32:07 ap4 dhcpcd[749]: wlan0: connected to Access Point: ministar Oct 14 15:32:07 ap4 dhcpcd[749]: wlan0: IAID eb:b7:f1:be Oct 14 15:32:07 ap4 dhcpcd[749]: wlan0: adding address fe80::57fa:1a90:3467:65e4 Oct 14 15:32:07 ap4 dhcpcd[749]: ipv6_addaddr1: Permission denied Oct 14 15:32:08 ap4 dhcpcd[749]: wlan0: soliciting an IPv6 router Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e8:9c:25:15:54:68 reason=3 locally_generated=1 Oct 14 15:32:08 ap4 dhcpcd[749]: wlan0: carrier lost - roaming Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=KR Oct 14 15:32:08 ap4 wireless.js[689]: WIRELESS.JS - INFO: DHCP IP fallback Oct 14 15:32:08 ap4 wireless.js[689]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Oct 14 15:32:08 ap4 wireless.js[689]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Oct 14 15:32:08 ap4 wireless.js[689]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> SCANNING (duration: 0ms) Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: Trying to associate with e8:9c:25:15:54:68 (SSID='ministar' freq=2417 MHz) Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: Associated with e8:9c:25:15:54:68 Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CN Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: WPA: Key negotiation completed with e8:9c:25:15:54:68 [PTK=CCMP GTK=CCMP] Oct 14 15:32:08 ap4 wpa_supplicant[1106]: wlan0: CTRL-EVENT-CONNECTED - Connection to e8:9c:25:15:54:68 completed [id=0 id_str=] Oct 14 15:32:08 ap4 dhcpcd[749]: wlan0: carrier acquired Oct 14 15:32:08 ap4 dhcpcd[749]: wlan0: IAID eb:b7:f1:be Oct 14 15:32:09 ap4 bash[955]: setdatetime-helper: all HTTPS Date fallbacks failed Oct 14 15:32:09 ap4 systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 14 15:32:09 ap4 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 14 15:32:09 ap4 systemd[1]: setdatetime-helper.service: Consumed 1.355s CPU time. Oct 14 15:32:09 ap4 wireless.js[689]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> COMPLETED (duration: 511ms) Oct 14 15:32:09 ap4 wireless.js[689]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Oct 14 15:32:09 ap4 wireless.js[689]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to e8:9c:25:15:54:68 Oct 14 15:32:09 ap4 wireless.js[689]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Oct 14 15:32:09 ap4 dhcpcd[749]: wlan0: soliciting an IPv6 router Oct 14 15:32:10 ap4 dhcpcd[749]: wlan0: rebinding lease of 192.168.1.202 Oct 14 15:32:10 ap4 sudo[1145]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Oct 14 15:32:10 ap4 sudo[1145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:10 ap4 dhcpcd[749]: control command: /sbin/dhcpcd wlan0 Oct 14 15:32:10 ap4 sudo[1145]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:10 ap4 dhcpcd[749]: control_free: No such file or directory Oct 14 15:32:11 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:11] [info] asio async_connect error: asio.system:111 (Connection refused) Oct 14 15:32:11 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:11] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Oct 14 15:32:11 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:11] [error] handle_connect error: Connection refused Oct 14 15:32:12 ap4 wireless.js[689]: WIRELESS.JS - INFO: Start ap Oct 14 15:32:12 ap4 wireless.js[689]: WIRELESS.JS - INFO: Notified systemd about wireless ready Oct 14 15:32:12 ap4 systemd[1]: Started wireless.service - Wireless Services. Oct 14 15:32:12 ap4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 14 15:32:12 ap4 systemd[1]: Started volumio.service - Volumio Backend Module. Oct 14 15:32:12 ap4 systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Oct 14 15:32:12 ap4 systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Oct 14 15:32:12 ap4 systemd[1]: Received SIGRTMIN+21 from PID 312 (plymouthd). Oct 14 15:32:12 ap4 systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Oct 14 15:32:12 ap4 systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Oct 14 15:32:12 ap4 systemd[1]: Received SIGRTMIN+21 from PID 312 (plymouthd). Oct 14 15:32:12 ap4 systemd[1]: Started getty@tty1.service - Getty on tty1. Oct 14 15:32:12 ap4 systemd[1]: Reached target getty.target - Login Prompts. Oct 14 15:32:12 ap4 volumio-cpu-tweak[1156]: Setting RT Priority for mpd Oct 14 15:32:12 ap4 volumio-cpu-tweak[1171]: pid 35's current scheduling policy: SCHED_OTHER Oct 14 15:32:12 ap4 volumio-cpu-tweak[1171]: pid 35's current scheduling priority: 0 Oct 14 15:32:12 ap4 volumio-cpu-tweak[1156]: Setting MPD Affinity Oct 14 15:32:12 ap4 volumio-cpu-tweak[1172]: pid 3's current affinity mask: f Oct 14 15:32:12 ap4 volumio-cpu-tweak[1156]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Oct 14 15:32:12 ap4 volumio-cpu-tweak[1156]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Oct 14 15:32:13 ap4 systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Oct 14 15:32:13 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:13 ap4 sudo[1185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:13 ap4 sudo[1185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:13 ap4 sudo[1185]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:13 ap4 sudo[1188]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:13 ap4 sudo[1188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:13 ap4 sudo[1188]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:13 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Oct 14 15:32:14 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:14 ap4 sudo[1199]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:14 ap4 sudo[1199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:14 ap4 sudo[1199]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:14 ap4 sudo[1202]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:14 ap4 sudo[1202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:14 ap4 sudo[1202]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:14 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Oct 14 15:32:14 ap4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Oct 14 15:32:14 ap4 dhcpcd[749]: wlan0: probing address 192.168.1.202/24 Oct 14 15:32:14 ap4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 14 15:32:14 ap4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 14 15:32:14 ap4 upmpdcli[1204]: Could not open config: /tmp/upmpdcli.conf Oct 14 15:32:14 ap4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 14 15:32:14 ap4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 14 15:32:15 ap4 wireless.js[689]: WIRELESS.JS - INFO: WARNING: dhcpcd running but no IP assigned yet Oct 14 15:32:15 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:15 ap4 sudo[1220]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:15 ap4 sudo[1220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:15 ap4 sudo[1220]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:15 ap4 sudo[1223]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:15 ap4 sudo[1223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:15 ap4 sudo[1223]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:15 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Oct 14 15:32:16 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:16 ap4 sudo[1234]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:16 ap4 sudo[1234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:16 ap4 sudo[1234]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:16 ap4 sudo[1237]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:16 ap4 sudo[1237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:16 ap4 sudo[1237]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:16 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Oct 14 15:32:17 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:32:17 ap4 volumio[1154]: info: ----- Volumio3 ---- Oct 14 15:32:17 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:32:17 ap4 volumio[1154]: info: ----- System startup ---- Oct 14 15:32:17 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:32:17 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:17 ap4 sudo[1254]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:17 ap4 sudo[1254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:17 ap4 sudo[1254]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:17 ap4 sudo[1257]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:17 ap4 sudo[1257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:17 ap4 sudo[1257]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:17 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Oct 14 15:32:18 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:18 ap4 sudo[1268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:18 ap4 sudo[1268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:18 ap4 sudo[1268]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:18 ap4 sudo[1271]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:18 ap4 sudo[1271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:18 ap4 sudo[1271]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:18 ap4 volumio[1154]: info: MYVOLUMIO Environment detected Oct 14 15:32:18 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Oct 14 15:32:19 ap4 volumio[1154]: info: Plugin folders cleanup Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning into folder /volumio/app/plugins/ Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning category audio_interface Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning category miscellanea Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning category music_service Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning category plugins.json Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning category system_controller Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning category user_interface Oct 14 15:32:19 ap4 volumio[1154]: info: Scanning into folder /data/plugins/ Oct 14 15:32:19 ap4 volumio[1154]: info: Plugin folders cleanup completed Oct 14 15:32:19 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:32:19 ap4 volumio[1154]: info: ----- Core plugins startup ---- Oct 14 15:32:19 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:32:19 ap4 volumio[1154]: info: Loading plugins from folder /volumio/app/plugins/ Oct 14 15:32:19 ap4 volumio[1154]: info: Adding plugin upnp to MyMusic Plugins Oct 14 15:32:19 ap4 volumio[1154]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 14 15:32:19 ap4 volumio[1154]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 14 15:32:19 ap4 volumio[1154]: info: Loading plugins from folder /data/plugins/ Oct 14 15:32:19 ap4 volumio[1154]: info: Loading plugin "system"... Oct 14 15:32:19 ap4 volumio[1154]: info: Loading plugin "appearance"... Oct 14 15:32:19 ap4 wireless.js[689]: WIRELESS.JS - INFO: trying... Oct 14 15:32:19 ap4 dhcpcd[749]: wlan0: leased 192.168.1.202 for 604800 seconds Oct 14 15:32:19 ap4 avahi-daemon[659]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.202. Oct 14 15:32:19 ap4 avahi-daemon[659]: New relevant interface wlan0.IPv4 for mDNS. Oct 14 15:32:19 ap4 avahi-daemon[659]: Registering new address record for 192.168.1.202 on wlan0.IPv4. Oct 14 15:32:19 ap4 dhcpcd[749]: wlan0: adding route to 192.168.1.0/24 Oct 14 15:32:19 ap4 dhcpcd[749]: wlan0: adding default route via 192.168.1.1 Oct 14 15:32:19 ap4 systemd[1]: Started nmbd.service - Samba NMB Daemon. Oct 14 15:32:19 ap4 systemd[1]: welcome.service: Deactivated successfully. Oct 14 15:32:19 ap4 systemd[1]: Stopped welcome.service - Show a welcome message on console. Oct 14 15:32:19 ap4 systemd[1]: Stopping welcome.service - Show a welcome message on console... Oct 14 15:32:19 ap4 sudo[1305]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 14 15:32:19 ap4 sudo[1305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:19 ap4 sudo[1305]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:19 ap4 systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 14 15:32:19 ap4 systemd[1]: Starting winbind.service - Samba Winbind Daemon... Oct 14 15:32:19 ap4 welcome[1310]: Resolved ip:[1] 192.168.1.202 Oct 14 15:32:19 ap4 sudo[1316]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:19 ap4 sudo[1316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:19 ap4 sudo[1316]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:19 ap4 wireless.js[689]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.1.202, ipV6 is undefined Oct 14 15:32:19 ap4 wireless.js[689]: WIRELESS.JS - INFO: Connected to SSID: ministar Oct 14 15:32:19 ap4 wireless.js[689]: WIRELESS.JS - INFO: It's done! AP Oct 14 15:32:19 ap4 systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 14 15:32:19 ap4 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Oct 14 15:32:19 ap4 wireless.js[689]: WIRELESS.JS - INFO: Restarting avahi-daemon... Oct 14 15:32:19 ap4 sudo[1324]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Oct 14 15:32:19 ap4 sudo[1324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:20 ap4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 14 15:32:20 ap4 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 14 15:32:20 ap4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:32:20 ap4 systemd[1]: shairport-sync.service: Consumed 1.703s CPU time. Oct 14 15:32:20 ap4 avahi-daemon[659]: Got SIGTERM, quitting. Oct 14 15:32:20 ap4 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Oct 14 15:32:20 ap4 avahi-daemon[659]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.202. Oct 14 15:32:20 ap4 avahi-daemon[659]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Oct 14 15:32:20 ap4 avahi-daemon[659]: avahi-daemon 0.8 exiting. Oct 14 15:32:20 ap4 systemd[1]: avahi-daemon.service: Deactivated successfully. Oct 14 15:32:20 ap4 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Oct 14 15:32:20 ap4 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Oct 14 15:32:20 ap4 avahi-daemon[1327]: Process 659 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Oct 14 15:32:20 ap4 avahi-daemon[1327]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Oct 14 15:32:20 ap4 avahi-daemon[1327]: Successfully dropped root privileges. Oct 14 15:32:20 ap4 avahi-daemon[1327]: avahi-daemon 0.8 starting up. Oct 14 15:32:20 ap4 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Oct 14 15:32:20 ap4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:32:20 ap4 sudo[1324]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:20 ap4 avahi-daemon[1327]: Successfully called chroot(). Oct 14 15:32:20 ap4 avahi-daemon[1327]: Successfully dropped remaining capabilities. Oct 14 15:32:20 ap4 avahi-daemon[1327]: Loading service file /services/volumio.service. Oct 14 15:32:20 ap4 avahi-daemon[1327]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.202. Oct 14 15:32:20 ap4 avahi-daemon[1327]: New relevant interface wlan0.IPv4 for mDNS. Oct 14 15:32:20 ap4 avahi-daemon[1327]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Oct 14 15:32:20 ap4 avahi-daemon[1327]: New relevant interface lo.IPv4 for mDNS. Oct 14 15:32:20 ap4 avahi-daemon[1327]: Network interface enumeration completed. Oct 14 15:32:20 ap4 avahi-daemon[1327]: Registering new address record for 192.168.1.202 on wlan0.IPv4. Oct 14 15:32:20 ap4 avahi-daemon[1327]: Registering new address record for 127.0.0.1 on lo.IPv4. Oct 14 15:32:20 ap4 wireless.js[689]: WIRELESS.JS - INFO: Notified systemd about wireless ready Oct 14 15:32:20 ap4 winbindd[1326]: [2026/10/14 15:32:20.684895, 0] ../../source3/winbindd/winbindd.c:1440(main) Oct 14 15:32:20 ap4 winbindd[1326]: winbindd version 4.17.8-Raspbian started. Oct 14 15:32:20 ap4 winbindd[1326]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 14 15:32:20 ap4 ntpd[972]: IO: Listen normally on 3 wlan0 192.168.1.202:123 Oct 14 15:32:20 ap4 ntpd[972]: IO: new interface(s) found: waking up resolver Oct 14 15:32:20 ap4 ntpd[972]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:20 ap4 winbindd[1326]: [2026/10/14 15:32:20.728314, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Oct 14 15:32:20 ap4 winbindd[1326]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 14 15:32:20 ap4 ntpd[972]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 14 15:32:20 ap4 ntpd[972]: DNS: Pool taking: 211.108.117.211 Oct 14 15:32:20 ap4 ntpd[972]: DNS: Pool taking: 121.174.142.81 Oct 14 15:32:20 ap4 ntpd[972]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Oct 14 15:32:20 ap4 systemd[1]: Started winbind.service - Samba Winbind Daemon. Oct 14 15:32:20 ap4 systemd[1]: Starting smbd.service - Samba SMB Daemon... Oct 14 15:32:21 ap4 avahi-daemon[1327]: Server startup complete. Host name is ap4.local. Local service cookie is 1011363780. Oct 14 15:32:21 ap4 ntpd[972]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:21 ap4 ntpd[972]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 14 15:32:21 ap4 ntpd[972]: DNS: Pool taking: 194.0.5.123 Oct 14 15:32:21 ap4 ntpd[972]: DNS: Pool taking: 115.15.44.33 Oct 14 15:32:21 ap4 ntpd[972]: DNS: Pool taking: 240b:400d:48:a500:453a:e00f:8fbd:cadf Oct 14 15:32:21 ap4 ntpd[972]: DNS: Pool taking: 2001:678:8::123 Oct 14 15:32:21 ap4 ntpd[972]: DNS: Pool taking: 2401:c080:1c00:24a1:5400:5ff:fe04:720 Oct 14 15:32:21 ap4 ntpd[972]: DNS: Pool taking: 240b:400d:48:a500:453a:e00f:8fbd:cae0 Oct 14 15:32:21 ap4 ntpd[972]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Oct 14 15:32:21 ap4 avahi-daemon[1327]: Service "AP4" (/services/volumio.service) successfully established. Oct 14 15:32:21 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:21] [connect] Successful connection Oct 14 15:32:21 ap4 smbd[1360]: [2026/10/14 15:32:21.855916, 0] ../../source3/smbd/server.c:1741(main) Oct 14 15:32:21 ap4 smbd[1360]: smbd version 4.17.8-Raspbian started. Oct 14 15:32:21 ap4 smbd[1360]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 14 15:32:22 ap4 ntpd[972]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:22 ap4 ntpd[972]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 14 15:32:22 ap4 ntpd[972]: DNS: Pool skipping: 211.108.117.211 Oct 14 15:32:22 ap4 ntpd[972]: DNS: Pool taking: 175.195.167.194 Oct 14 15:32:22 ap4 ntpd[972]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Oct 14 15:32:23 ap4 volumio[1154]: info: Loading plugin "network"... Oct 14 15:32:23 ap4 volumio[1154]: info: Refreshing Cached IP Addresses Oct 14 15:32:23 ap4 sudo[1373]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 14 15:32:23 ap4 sudo[1373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:23 ap4 sudo[1373]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:23 ap4 volumio[1154]: info: Loading plugin "services"... Oct 14 15:32:23 ap4 volumio[1154]: info: Loading plugin "volumio5onboarding"... Oct 14 15:32:23 ap4 sudo[1375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:32:23 ap4 sudo[1375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:23 ap4 sudo[1380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 14 15:32:23 ap4 sudo[1375]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:23 ap4 sudo[1380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:23 ap4 volumio[1154]: info: Loading plugin "alsa_controller"... Oct 14 15:32:23 ap4 ntpd[972]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 15:32:23 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 14 15:32:23 ap4 volumio[1154]: info: Loading plugin "wizard"... Oct 14 15:32:23 ap4 systemd[1]: Started smbd.service - Samba SMB Daemon. Oct 14 15:32:23 ap4 systemd[1]: Reached target multi-user.target - Multi-User System. Oct 14 15:32:23 ap4 systemd[1]: Reached target graphical.target - Graphical Interface. Oct 14 15:32:23 ap4 volumio[1154]: info: Loading plugin "networkfs"... Oct 14 15:32:23 ap4 ntpd[972]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 14 15:32:23 ap4 ntpd[972]: DNS: Pool taking: 193.123.243.2 Oct 14 15:32:23 ap4 ntpd[972]: DNS: Pool skipping: 194.0.5.123 Oct 14 15:32:23 ap4 ntpd[972]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Oct 14 15:32:23 ap4 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Oct 14 15:32:23 ap4 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Oct 14 15:32:23 ap4 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Oct 14 15:32:23 ap4 systemd[1]: Startup finished in 15.714s (kernel) + 30.483s (userspace) = 46.197s. Oct 14 15:32:23 ap4 volumio[1154]: info: Starting Udev Watcher for removable devices Oct 14 15:32:23 ap4 sudo[1409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=kimgun,password=Sinbi511781,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.201/music /mnt/NAS/Synology Oct 14 15:32:23 ap4 sudo[1409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:24 ap4 volumio[1154]: info: Ignoring mount for partition: boot Oct 14 15:32:24 ap4 volumio[1154]: info: Ignoring mount for partition: volumio Oct 14 15:32:24 ap4 volumio[1154]: info: Ignoring mount for partition: volumio_data Oct 14 15:32:24 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 14 15:32:24 ap4 kernel: netfs: FS-Cache loaded Oct 14 15:32:24 ap4 volumio[1154]: info: Loading plugin "volumio_command_line_client"... Oct 14 15:32:24 ap4 volumio[1154]: info: Loading plugin "upnp"... Oct 14 15:32:24 ap4 volumio[1154]: info: [1791959544155] Starting Upmpd Daemon Oct 14 15:32:24 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 14 15:32:24 ap4 volumio[1154]: info: Loading plugin "my_music"... Oct 14 15:32:24 ap4 volumio[1154]: info: Loading plugin "mpd"... Oct 14 15:32:24 ap4 sudo[1380]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:24 ap4 kernel: Key type cifs.spnego registered Oct 14 15:32:24 ap4 kernel: Key type cifs.idmap registered Oct 14 15:32:24 ap4 kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Oct 14 15:32:24 ap4 kernel: CIFS: Attempting to mount //192.168.1.201/music Oct 14 15:32:24 ap4 sudo[1409]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:25 ap4 volumio[1154]: info: Loading plugin "upnp_browser"... Oct 14 15:32:26 ap4 systemd[1]: systemd-fsckd.service: Deactivated successfully. Oct 14 15:32:50 ap4 ntpd[972]: CLOCK: time stepped by 22.966659 Oct 14 15:32:50 ap4 ntpd[972]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 14 15:32:50 ap4 volumio[1154]: info: Starting UPNP Browser Oct 14 15:32:50 ap4 volumio[1154]: info: Loading plugin "alarm-clock"... Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "airplay_emulation"... Oct 14 15:32:51 ap4 volumio[1154]: info: Starting Shairport Sync Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "last_100"... Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "webradio"... Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "i2s_dacs"... Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "volumiodiscovery"... Oct 14 15:32:51 ap4 sh[675]: timed out Oct 14 15:32:51 ap4 dhcpcd[680]: timed out Oct 14 15:32:51 ap4 volumio[1154]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 14 15:32:51 ap4 volumio[1154]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 14 15:32:51 ap4 volumio[1154]: *** WARNING *** For more information see Oct 14 15:32:51 ap4 volumio[1154]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 14 15:32:51 ap4 volumio[1154]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 14 15:32:51 ap4 volumio[1154]: *** WARNING *** For more information see Oct 14 15:32:51 ap4 node[1154]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 14 15:32:51 ap4 node[1154]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 14 15:32:51 ap4 node[1154]: *** WARNING *** For more information see Oct 14 15:32:51 ap4 node[1154]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 14 15:32:51 ap4 node[1154]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 14 15:32:51 ap4 node[1154]: *** WARNING *** For more information see Oct 14 15:32:51 ap4 volumio[1154]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 14 15:32:51 ap4 sh[644]: ifup: failed to bring up eth0 Oct 14 15:32:51 ap4 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Oct 14 15:32:51 ap4 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Oct 14 15:32:51 ap4 volumio[1154]: info: Discovery: Started advertising with name: AP4 Oct 14 15:32:51 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "outputs"... Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "albumart"... Oct 14 15:32:51 ap4 volumio[1154]: info: Plugin example_plugin is not enabled Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "inputs"... Oct 14 15:32:51 ap4 volumio[1154]: info: Loading plugin "updater_comm"... Oct 14 15:32:52 ap4 volumio[1154]: info: Plugin mpdemulation is not enabled Oct 14 15:32:52 ap4 volumio[1154]: info: Loading plugin "rest_api"... Oct 14 15:32:52 ap4 volumio[1154]: info: Loading plugin "websocket"... Oct 14 15:32:52 ap4 volumio[1154]: info: Starting Socket.io Server version 1.7.4 Oct 14 15:32:52 ap4 volumio[1154]: info: Loading i18n strings for locale ko Oct 14 15:32:52 ap4 volumio[1154]: Updating browse sources language Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::initPlayerControls Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: Express server listening on port 3000 Oct 14 15:32:52 ap4 volumio[1154]: [Metrics] WebUI: 13s 256.21ms Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::resetVolumioState Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::getcurrentVolume Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::volumioRetrievevolume Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::pushState Oct 14 15:32:52 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::volumioPushState Oct 14 15:32:52 ap4 volumio[1154]: info: Volumio Network Manager: Network status updated: 2 Oct 14 15:32:52 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 14 15:32:52 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:32:52 ap4 volumio[1154]: info: Reloading queue from file Oct 14 15:32:52 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::setRepeat null single undefined Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::pushState Oct 14 15:32:52 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::volumioPushState Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::setRandom null Oct 14 15:32:52 ap4 volumio[1154]: info: CoreStateMachine::pushState Oct 14 15:32:52 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:32:52 ap4 volumio[1154]: info: CoreCommandRouter::volumioPushState Oct 14 15:32:52 ap4 volumio[1154]: info: Setting Device type: Raspberry PI Oct 14 15:32:52 ap4 volumio[1154]: info: Completed loading Core Plugins Oct 14 15:32:52 ap4 volumio[1154]: info: Preparing to generate the ALSA configuration file Oct 14 15:32:52 ap4 volumio[1154]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 14 15:32:52 ap4 volumio[1154]: info: USB Boot Capable - System SBC Revision found in cpuinfo: a32082 Oct 14 15:32:52 ap4 volumio[1154]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 14 15:32:52 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Oct 14 15:32:52 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 14 15:32:52 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 14 15:32:52 ap4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Oct 14 15:32:52 ap4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 14 15:32:52 ap4 volumio[1154]: info: Discovery: adding d3f48bd8-f79d-4fd2-a87b-a189ac40edb7 Oct 14 15:32:52 ap4 volumio[1154]: info: Discovery: Found device AP4 Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::volumioGetState Oct 14 15:32:53 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:32:53 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Oct 14 15:32:53 ap4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 14 15:32:53 ap4 volumio[1154]: info: Asound.conf file unchanged, so no further update is needed Oct 14 15:32:53 ap4 volumio[1154]: info: Output device has changed, restarting MPD Oct 14 15:32:53 ap4 upmpdcli[1474]: Could not open config: /tmp/upmpdcli.conf Oct 14 15:32:53 ap4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 14 15:32:53 ap4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 14 15:32:53 ap4 volumio[1154]: info: Output device has changed, restarting Shairport Sync Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 14 15:32:53 ap4 volumio[1154]: info: ___________ START PLUGINS ___________ Oct 14 15:32:53 ap4 sudo[1476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 14 15:32:53 ap4 volumio[1154]: info: ControllerMpd::onStart: Initializing MPD Oct 14 15:32:53 ap4 volumio[1154]: info: Creating MPD Configuration file Oct 14 15:32:53 ap4 sudo[1478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 14 15:32:53 ap4 sudo[1478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:53 ap4 sudo[1476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:53 ap4 sudo[1484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 14 15:32:53 ap4 sudo[1476]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:53 ap4 sudo[1484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 14 15:32:53 ap4 volumio[1154]: info: [1791959573280] CoreMusicLibrary::Adding element 미디어 서버 Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 15:32:53 ap4 sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 14 15:32:53 ap4 sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:53 ap4 volumio[1154]: info: UPNP Browser: Client initialized successfully Oct 14 15:32:53 ap4 sudo[1487]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:53 ap4 sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 14 15:32:53 ap4 sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:32:53 ap4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 14 15:32:53 ap4 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 14 15:32:53 ap4 volumio[1154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 14 15:32:53 ap4 volumio[1154]: info: [1791959573563] CoreMusicLibrary::Adding element Last_100 Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 14 15:32:53 ap4 volumio[1154]: info: [1791959573579] CoreMusicLibrary::Adding element Webradio Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 15:32:53 ap4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 14 15:32:53 ap4 sudo[1484]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:53 ap4 systemd[1]: mpd.service: Deactivated successfully. Oct 14 15:32:53 ap4 systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 14 15:32:53 ap4 volumio[1154]: info: Initializing BBC Radios Oct 14 15:32:53 ap4 systemd[1]: mpd.socket: Deactivated successfully. Oct 14 15:32:53 ap4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 14 15:32:53 ap4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 14 15:32:53 ap4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 14 15:32:53 ap4 systemd[1]: Starting mpd.service - Music Player Daemon... Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 14 15:32:53 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:32:53 ap4 volumio[1154]: info: Volumio Calling Home Oct 14 15:32:53 ap4 sudo[1508]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 14 15:32:53 ap4 sudo[1508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 14 15:32:54 ap4 sudo[1527]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 14 15:32:54 ap4 sudo[1508]: pam_unix(sudo:session): session closed for user root Oct 14 15:32:54 ap4 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Oct 14 15:32:54 ap4 volumio5-onboarding[1504]: time=2026-10-14T15:32:54.492+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 14 15:32:54 ap4 volumio[1450]: Forking 3 albumart workers Oct 14 15:32:59 ap4 volumio[1154]: info: Discovery: this is already registered, d3f48bd8-f79d-4fd2-a87b-a189ac40edb7 Oct 14 15:32:59 ap4 volumio[1154]: info: Discovery: Found device AP4 Oct 14 15:32:59 ap4 volumio[1154]: info: CoreCommandRouter::volumioGetState Oct 14 15:32:59 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:32:59 ap4 volumio-remote-updater[686]: [2026-10-14 15:32:59] [connect] Successful connection Oct 14 15:32:59 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 14 15:33:00 ap4 sudo[1581]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 14 15:33:00 ap4 sudo[1581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:00 ap4 sudo[1583]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:33:00 ap4 sudo[1583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:00 ap4 sudo[1583]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:00 ap4 sudo[1581]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:01 ap4 volumio[1154]: info: Discovery: adding 6baba620-722e-49e3-93cc-d2edc0c81484 Oct 14 15:33:01 ap4 volumio[1154]: info: Discovery: Found device Marshall Oct 14 15:33:01 ap4 volumio[1154]: info: Discovery: Connecting to remote: 192.168.1.213 Oct 14 15:33:01 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 14 15:33:02 ap4 volumio[1154]: info: MPD Permissions set Oct 14 15:33:02 ap4 mpd[1530]: 2026-10-14T15:33:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 14 15:33:02 ap4 volumio[1154]: info: MPD Permissions set Oct 14 15:33:02 ap4 systemd[1]: Started mpd.service - Music Player Daemon. Oct 14 15:33:02 ap4 sudo[1491]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:02 ap4 sudo[1478]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:02 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Oct 14 15:33:02 ap4 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 14 15:33:04 ap4 volumio5-onboarding[1504]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:59510->127.0.0.1:3000: i/o timeout Oct 14 15:33:04 ap4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 14 15:33:04 ap4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 14 15:33:04 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 14 15:33:04 ap4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Oct 14 15:33:04 ap4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 14 15:33:04 ap4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 14 15:33:04 ap4 volumio5-onboarding[1610]: time=2026-10-14T15:33:04.815+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 14 15:33:04 ap4 volumio[1154]: info: Completed starting Core Plugins Oct 14 15:33:04 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:33:04 ap4 volumio[1154]: info: ----- MyVolumio plugins startup ---- Oct 14 15:33:04 ap4 volumio[1154]: info: ------------------------------------------- Oct 14 15:33:04 ap4 volumio[1154]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 14 15:33:04 ap4 volumio[1154]: info: Volumio called home Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:04 ap4 systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 14 15:33:04 ap4 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 14 15:33:04 ap4 systemd[1]: setdatetime-helper.service: Consumed 1.032s CPU time. Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:33:05 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 14 15:33:06 ap4 volumio[1536]: Starting albumart workers Oct 14 15:33:06 ap4 volumio[1154]: info: MPD running with PID1530 Oct 14 15:33:06 ap4 volumio[1154]: ,establishing connection Oct 14 15:33:07 ap4 volumio[1537]: Starting albumart workers Oct 14 15:33:07 ap4 volumio[1535]: Starting albumart workers Oct 14 15:33:07 ap4 volumio[1154]: error: MPD error: The expression evaluated to a falsy value: Oct 14 15:33:07 ap4 volumio[1154]: assert.ok(self.idling) Oct 14 15:33:07 ap4 volumio[1154]: error: The expression evaluated to a falsy value: Oct 14 15:33:07 ap4 volumio[1154]: assert.ok(self.idling) Oct 14 15:33:07 ap4 volumio[1154]: error: MPD error: The expression evaluated to a falsy value: Oct 14 15:33:07 ap4 volumio[1154]: assert.ok(self.idling) Oct 14 15:33:07 ap4 volumio[1154]: error: The expression evaluated to a falsy value: Oct 14 15:33:07 ap4 volumio[1154]: assert.ok(self.idling) Oct 14 15:33:07 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 14 15:33:07 ap4 volumio[1154]: info: Discovery: Connected to remote: 192.168.1.213 Oct 14 15:33:07 ap4 volumio[1154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Oct 14 15:33:08 ap4 volumio[1154]: info: Starting Shairport Sync Oct 14 15:33:08 ap4 volumio[1154]: info: Starting Shairport Sync Oct 14 15:33:08 ap4 sudo[1655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 14 15:33:08 ap4 volumio[1154]: info: Starting Shairport Sync Oct 14 15:33:08 ap4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Oct 14 15:33:08 ap4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 14 15:33:08 ap4 sudo[1655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:08 ap4 volumio[1154]: error: updateQueue error: null Oct 14 15:33:08 ap4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 14 15:33:08 ap4 sudo[1660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 14 15:33:08 ap4 sudo[1660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:08 ap4 sudo[1658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 14 15:33:08 ap4 sudo[1658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:08 ap4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 14 15:33:08 ap4 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 14 15:33:08 ap4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:33:08 ap4 sudo[1656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 14 15:33:08 ap4 systemd[1]: shairport-sync.service: Consumed 1.347s CPU time. Oct 14 15:33:08 ap4 sudo[1656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:08 ap4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:33:08 ap4 sudo[1660]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:08 ap4 sudo[1658]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:08 ap4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 14 15:33:08 ap4 systemd[1]: shairport-sync.service: Deactivated successfully. Oct 14 15:33:08 ap4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:33:08 ap4 sudo[1655]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:08 ap4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 14 15:33:08 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Oct 14 15:33:08 ap4 sudo[1656]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:09 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15 Oct 14 15:33:09 ap4 volumio[1154]: info: Shairport-Sync Started Oct 14 15:33:09 ap4 volumio[1154]: Error adding Membership: Error: addMembership EINVAL Oct 14 15:33:09 ap4 volumio[1154]: info: Upmpdcli Daemon Started Oct 14 15:33:09 ap4 volumio[1154]: info: Shairport-Sync Started Oct 14 15:33:09 ap4 volumio[1154]: info: Shairport-Sync Started Oct 14 15:33:09 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Oct 14 15:33:09 ap4 volumio[1154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 17 Oct 14 15:33:10 ap4 volumio[1154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 17 Oct 14 15:33:10 ap4 volumio[1154]: info: Received Get System Info Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 14 15:33:10 ap4 volumio[1154]: info: Discovery: Getting this device information Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::volumioGetState Oct 14 15:33:10 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 14 15:33:10 ap4 volumio5-onboarding[1610]: time=2026-10-14T15:33:10.378+09:00 level=INFO msg="system info for 89b38baf4a3668f8e902dccf6caa0500" deviceName=AP4 deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 14 15:33:10 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202:3000 from 192.168.1.213 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Oct 14 15:33:10 ap4 volumio5-onboarding[1610]: time=2026-10-14T15:33:10.414+09:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 14 15:33:10 ap4 volumio[1154]: info: Received Get System Info Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 14 15:33:10 ap4 volumio[1154]: info: Discovery: Getting this device information Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::volumioGetState Oct 14 15:33:10 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:33:10 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 14 15:33:10 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 19 Oct 14 15:33:11 ap4 volumio[1154]: info: CoreCommandRouter::volumioGetState Oct 14 15:33:11 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:33:11 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 14 15:33:11 ap4 volumio[1154]: info: CoreCommandRouter::volumioGetState Oct 14 15:33:11 ap4 volumio[1154]: info: CorePlayQueue::getTrack 0 Oct 14 15:33:12 ap4 sudo[1719]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 14 15:33:12 ap4 sudo[1719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:12 ap4 volumio[1154]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 14 15:33:12 ap4 sudo[1719]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:12 ap4 sudo[1722]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 15:33:12 ap4 sudo[1722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:12 ap4 sudo[1722]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:14 ap4 volumio-remote-updater[686]: [2026-10-14 15:33:14] [connect] Successful connection Oct 14 15:33:16 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 20 Oct 14 15:33:21 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 21 Oct 14 15:33:23 ap4 volumio[1154]: verbose: New Socket.io Connection to 192.168.1.202 from 192.168.1.68 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 22 Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 14 15:33:28 ap4 volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin bluetooth to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin multiroom to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin metavolumio to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin cd_controller to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 14 15:33:29 ap4 volumio[1154]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 14 15:33:29 ap4 volumio-remote-updater[686]: [2026-10-14 15:33:29] [connect] Successful connection Oct 14 15:33:31 ap4 upmpdcli[1766]: writing RSA key Oct 14 15:33:36 ap4 volumio[1154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 14 15:33:36 ap4 volumio[1154]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 14 15:33:36 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:33:36 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:33:36 ap4 volumio[1154]: info: Starting MyVolumio Remote Streaming Endpoints Oct 14 15:33:36 ap4 volumio[1154]: info: MyVolumio login type: Token Oct 14 15:33:36 ap4 volumio[1154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 14 15:33:36 ap4 volumio[1154]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 14 15:33:39 ap4 volumio[1154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 14 15:33:39 ap4 volumio[1154]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 14 15:33:39 ap4 volumio[1154]: info: Streaming services startup Oct 14 15:33:39 ap4 volumio[1154]: info: Starting Streaming Daemon Oct 14 15:33:39 ap4 volumio[1154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 14 15:33:39 ap4 sudo[1791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 14 15:33:39 ap4 sudo[1791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 15:33:39 ap4 sudo[1791]: pam_unix(sudo:session): session closed for user root Oct 14 15:33:40 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 14 15:33:40 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 14 15:33:40 ap4 volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 14 15:33:40 ap4 volumio[1154]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 14 15:33:40 ap4 volumio[1154]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Oct 14 15:33:40 ap4 volumio[1154]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Oct 14 15:33:40 ap4 volumio[1154]: at new NodeError (node:internal/errors:405:5) Oct 14 15:33:40 ap4 volumio[1154]: at assert (node:internal/assert:14:11) Oct 14 15:33:40 ap4 volumio[1154]: at internalConnectMultiple (node:net:1118:3) Oct 14 15:33:40 ap4 volumio[1154]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Oct 14 15:33:40 ap4 volumio[1154]: at listOnTimeout (node:internal/timers:575:11) Oct 14 15:33:40 ap4 volumio[1154]: at process.processTimers (node:internal/timers:514:7) { Oct 14 15:33:40 ap4 volumio[1154]: code: 'ERR_INTERNAL_ASSERTION' Oct 14 15:33:40 ap4 volumio[1154]: } Oct 14 15:33:40 ap4 volumio[1154]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 14 15:33:40 ap4 volumio5-onboarding[1610]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Oct 14 15:33:40 ap4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 14 15:33:40 ap4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 14 15:33:40 ap4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Oct 14 15:33:40 ap4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 14 15:33:40 ap4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 14 15:33:40 ap4 volumio5-onboarding[1811]: time=2026-10-14T15:33:40.806+09:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 14 15:33:44 ap4 volumio-remote-updater[686]: [2026-10-14 15:33:44] [connect] Successful connection Oct 14 15:33:46 ap4 sudo[1821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-14 15:32' Oct 14 15:33:46 ap4 sudo[1821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"