Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event3 (Power Button) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event2 (Power Button) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event1 (Lid Switch) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event0 (Sleep Button) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event14 (Intel HID events) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event15 (Intel HID 5 button array) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event4 (AT Translated Set 2 keyboard) Aug 26 15:27:00 volumio systemd-logind[978]: Watching system buttons on /dev/input/event16 (HP WMI hotkeys) Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event1 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event10 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event11 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event12 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event13 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event14 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event15 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event16 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event2 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event3 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event4 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event5 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event6 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event7 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event8 to thd using --add... Aug 26 15:27:00 volumio th-udev-rebind.sh[997]: Rebinding /dev/input/event9 to thd using --add... Aug 26 15:27:00 volumio dhcpcd[1007]: dev: loaded udev Aug 26 15:27:00 volumio dhcpcd[1007]: DUID 00:04:a1:8a:d4:7d:5b:c2:13:44:73:d7:00:c3:f9:25:c9:7f Aug 26 15:27:00 volumio systemd[1]: th-udev-rebind.service: Deactivated successfully. Aug 26 15:27:00 volumio systemd[1]: Finished th-udev-rebind.service - Late rebind of input devices to triggerhappy. Aug 26 15:27:00 volumio bluetoothd[972]: Bluetooth daemon 5.83 Aug 26 15:27:00 volumio acpid[969]: starting up with netlink and the input layer Aug 26 15:27:00 volumio acpid[969]: 3 rules loaded Aug 26 15:27:00 volumio acpid[969]: waiting for events: event logging is off Aug 26 15:27:00 volumio systemd[1]: Started dhcpcd.service - DHCP Client Daemon on all interfaces. Aug 26 15:27:00 volumio kernel: 8021q: 802.1Q VLAN Support v1.8 Aug 26 15:27:00 volumio systemd[1]: Started dbus.service - D-Bus System Message Bus. Aug 26 15:27:00 volumio avahi-daemon[971]: Successfully called chroot(). Aug 26 15:27:00 volumio avahi-daemon[971]: Successfully dropped remaining capabilities. Aug 26 15:27:00 volumio dbus-daemon[973]: [system] Successfully activated service 'org.freedesktop.systemd1' Aug 26 15:27:00 volumio bluetoothd[972]: Starting SDP server Aug 26 15:27:00 volumio bluetoothd[972]: Excluding (cli) sap Aug 26 15:27:00 volumio bluetoothd[972]: Excluding (cli) scanparam Aug 26 15:27:00 volumio bluetoothd[972]: Excluding (cli) midi Aug 26 15:27:00 volumio bluetoothd[972]: Excluding (cli) battery Aug 26 15:27:00 volumio avahi-daemon[971]: No service file found in /etc/avahi/services. Aug 26 15:27:00 volumio avahi-daemon[971]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 26 15:27:00 volumio avahi-daemon[971]: New relevant interface lo.IPv4 for mDNS. Aug 26 15:27:00 volumio avahi-daemon[971]: Network interface enumeration completed. Aug 26 15:27:00 volumio avahi-daemon[971]: Registering new address record for 127.0.0.1 on lo.IPv4. Aug 26 15:27:00 volumio systemd[1]: Starting wpa_supplicant.service - WPA supplicant... Aug 26 15:27:00 volumio systemd[1]: Started systemd-logind.service - User Login Management. Aug 26 15:27:00 volumio systemd[1]: Started bluetooth.service - Bluetooth service. Aug 26 15:27:00 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 26 15:27:00 volumio systemd[1]: Starting bluealsa.service - BlueALSA service... Aug 26 15:27:00 volumio bluetoothd[972]: Bluetooth management interface 1.23 initialized Aug 26 15:27:00 volumio dbus-daemon[973]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.2' (uid=0 pid=972 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 26 15:27:00 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Aug 26 15:27:00 volumio kernel: Bluetooth: BNEP filters: protocol multicast Aug 26 15:27:00 volumio kernel: Bluetooth: BNEP socket layer initialized Aug 26 15:27:00 volumio systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Aug 26 15:27:00 volumio dhcpcd[1007]: wlan0: waiting for carrier Aug 26 15:27:00 volumio systemd[1]: iptables.service: Deactivated successfully. Aug 26 15:27:00 volumio systemd[1]: Mounting run-rpc_pipefs.mount - RPC Pipe File System... Aug 26 15:27:00 volumio dbus-daemon[973]: [system] Successfully activated service 'org.freedesktop.hostname1' Aug 26 15:27:00 volumio systemd[1]: Started systemd-hostnamed.service - Hostname Service. Aug 26 15:27:00 volumio wpa_supplicant[1038]: Successfully initialized wpa_supplicant Aug 26 15:27:00 volumio systemd[1]: Started wpa_supplicant.service - WPA supplicant. Aug 26 15:27:00 volumio systemd[1]: Reached target network.target - Network. Aug 26 15:27:00 volumio systemd[1]: Reached target network-online.target - Network is Online. Aug 26 15:27:00 volumio volumio-remote-updater[982]: Volumio OTA Client: 1.7.0 Aug 26 15:27:00 volumio volumio-remote-updater[982]: Error: No active session Aug 26 15:27:00 volumio volumio-remote-updater[982]: [2026-08-26 15:27:00] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 26 15:27:00 volumio volumio-remote-updater[982]: [2026-08-26 15:27:00] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 26 15:27:00 volumio volumio-remote-updater[982]: [2026-08-26 15:27:00] [error] handle_connect error: Connection refused Aug 26 15:27:00 volumio upmpdcli[981]: Could not open config: /tmp/upmpdcli.conf Aug 26 15:27:00 volumio kernel: RPC: Registered named UNIX socket transport module. Aug 26 15:27:00 volumio kernel: RPC: Registered udp transport module. Aug 26 15:27:00 volumio kernel: RPC: Registered tcp transport module. Aug 26 15:27:00 volumio kernel: RPC: Registered tcp-with-tls transport module. Aug 26 15:27:00 volumio kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Aug 26 15:27:00 volumio systemd[1]: Starting nmbd.service - Samba NMB Daemon... Aug 26 15:27:00 volumio systemd[1]: Starting ntpsec.service - Network Time Service... Aug 26 15:27:00 volumio systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... Aug 26 15:27:00 volumio systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart... Aug 26 15:27:00 volumio systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon... Aug 26 15:27:00 volumio sm-notify[1060]: Version 2.6.2 starting Aug 26 15:27:00 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 26 15:27:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:00 volumio systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor. Aug 26 15:27:00 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 26 15:27:00 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:00 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 26 15:27:00 volumio systemd[1]: Mounted run-rpc_pipefs.mount - RPC Pipe File System. Aug 26 15:27:00 volumio systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. Aug 26 15:27:00 volumio systemd[1]: Reached target rpc_pipefs.target. Aug 26 15:27:00 volumio systemd[1]: rpc-gssd.service - RPC security service for NFS client and server was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab). Aug 26 15:27:00 volumio systemd[1]: Reached target nfs-client.target - NFS client services. Aug 26 15:27:00 volumio systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Aug 26 15:27:00 volumio systemd[1]: Reached target remote-fs.target - Remote File Systems. Aug 26 15:27:00 volumio systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically... Aug 26 15:27:00 volumio systemd[1]: Starting loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling... Aug 26 15:27:00 volumio systemd[1]: systemd-pcrphase.service - TPM2 PCR Barrier (User) was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f). Aug 26 15:27:00 volumio systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Aug 26 15:27:00 volumio systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart. Aug 26 15:27:00 volumio welcome[1066]: Resolved ip:[0] Aug 26 15:27:00 volumio systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Aug 26 15:27:00 volumio systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... Aug 26 15:27:00 volumio systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Aug 26 15:27:00 volumio ntpd[1067]: INIT: ntpd ntpsec-1.2.2: Starting Aug 26 15:27:00 volumio ntpd[1067]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Aug 26 15:27:00 volumio ntp-systemd-wrapper[1067]: 2026-08-26T15:27:00 ntpd[1067]: INIT: ntpd ntpsec-1.2.2: Starting Aug 26 15:27:00 volumio ntp-systemd-wrapper[1067]: 2026-08-26T15:27:00 ntpd[1067]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Aug 26 15:27:00 volumio systemd[1]: Started ntpsec.service - Network Time Service. Aug 26 15:27:00 volumio ntpd[1093]: INIT: precision = 0.115 usec (-23) Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Waiting for firmware download to complete Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Firmware loaded in 1874652 usecs Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Waiting for device to boot Aug 26 15:27:00 volumio ntpd[1093]: INIT: successfully locked into RAM Aug 26 15:27:00 volumio ntpd[1093]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf Aug 26 15:27:00 volumio ntpd[1093]: CONFIG: restrict nopeer ignored Aug 26 15:27:00 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Device booted in 14624 usecs Aug 26 15:27:00 volumio ntpd[1093]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Aug 26 15:27:00 volumio ntpd[1093]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2026-06-28T00:00Z last=2017-01-01T00:00Z ofs=37 Aug 26 15:27:00 volumio ntpd[1093]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 60 days ago Aug 26 15:27:00 volumio ntpd[1093]: INIT: Using SO_TIMESTAMPNS(ns) Aug 26 15:27:00 volumio ntpd[1093]: IO: Listen and drop on 0 v6wildcard [::]:123 Aug 26 15:27:00 volumio ntpd[1093]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123 Aug 26 15:27:00 volumio ntpd[1093]: IO: Listen normally on 2 lo 127.0.0.1:123 Aug 26 15:27:00 volumio ntpd[1093]: IO: Listening on routing socket on fd #19 for interface updates Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-20-1-3.ddc Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Applying Intel DDC parameters completed Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: Firmware revision 0.3 build 132 week 3 2024 Aug 26 15:27:00 volumio kernel: Bluetooth: hci0: HCI LE Coded PHY feature bit is set, but its usage is not supported. Aug 26 15:27:00 volumio ntpd[1093]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes Aug 26 15:27:00 volumio ntpd[1093]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090 Aug 26 15:27:00 volumio ntpd[1093]: INIT: Running with OpenSSL 3.0.18 30 Sep 2025, 30000120 Aug 26 15:27:00 volumio ntpd[1093]: NTSc: Using system default root certificates. Aug 26 15:27:00 volumio bluealsa[1045]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa Aug 26 15:27:00 volumio bluealsa[1045]: main.c:663: Starting main dispatching loop Aug 26 15:27:00 volumio systemd[1]: Started bluealsa.service - BlueALSA service. Aug 26 15:27:00 volumio bluealsa[1045]: main.c:118: Acquired D-Bus service name: org.bluealsa Aug 26 15:27:00 volumio bluealsa[1045]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa Aug 26 15:27:00 volumio systemd[1]: Reached target bluetooth.target - Bluetooth Support. Aug 26 15:27:00 volumio bluetoothd[972]: Battery Provider Manager created Aug 26 15:27:00 volumio kernel: Bluetooth: MGMT ver 1.23 Aug 26 15:27:00 volumio kernel: NET: Registered PF_ALG protocol family Aug 26 15:27:00 volumio ntpd[1093]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory Aug 26 15:27:00 volumio bluetoothd[972]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled Aug 26 15:27:00 volumio bluetoothd[972]: bap: Operation not supported (95) Aug 26 15:27:00 volumio bluetoothd[972]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16 Aug 26 15:27:00 volumio bluealsa[1045]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0, ...) Aug 26 15:27:00 volumio bluealsa[1045]: bluez.c:153: Registering media application: /org/bluez/hci0 Aug 26 15:27:00 volumio bluealsa[1045]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1 Aug 26 15:27:00 volumio bluealsa[1045]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2 Aug 26 15:27:00 volumio bluealsa[1045]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1 Aug 26 15:27:00 volumio bluealsa[1045]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2 Aug 26 15:27:00 volumio bluetoothd[972]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/1 Aug 26 15:27:00 volumio bluetoothd[972]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/2 Aug 26 15:27:00 volumio bluetoothd[972]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/1 Aug 26 15:27:00 volumio bluetoothd[972]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/2 Aug 26 15:27:00 volumio bash[1142]: mount: /cpusets: unknown filesystem type 'cpuset'. Aug 26 15:27:00 volumio bash[1142]: dmesg(1) may have more information after failed mount system call. Aug 26 15:27:01 volumio avahi-daemon[971]: Server startup complete. Host name is volumio.local. Local service cookie is 3024894519. Aug 26 15:27:01 volumio bash[1153]: mount: /cpusets: unknown filesystem type 'cpuset'. Aug 26 15:27:01 volumio bash[1153]: dmesg(1) may have more information after failed mount system call. Aug 26 15:27:01 volumio bash[1150]: cset: **> mount of cpuset filesystem failed, do you have permission? Aug 26 15:27:01 volumio systemd[1]: Finished musicservicesshield.service - Shield Volumio Music Services in the User CPU Set. Aug 26 15:27:01 volumio systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Aug 26 15:27:01 volumio systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Aug 26 15:27:01 volumio wireless.js[983]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Aug 26 15:27:01 volumio wireless.js[983]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Aug 26 15:27:01 volumio nmbd[1164]: [2026/08/26 15:27:01.241229, 0] ../../source3/nmbd/nmbd.c:901(main) Aug 26 15:27:01 volumio nmbd[1164]: nmbd version 4.17.12-Debian started. Aug 26 15:27:01 volumio nmbd[1164]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Aug 26 15:27:01 volumio nmbd[1164]: [2026/08/26 15:27:01.244690, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Aug 26 15:27:01 volumio nmbd[1164]: started asyncdns process 1173 Aug 26 15:27:01 volumio nmbd[1164]: [2026/08/26 15:27:01.245085, 0] ../../lib/util/become_daemon.c:150(daemon_status) Aug 26 15:27:01 volumio nmbd[1164]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Aug 26 15:27:01 volumio nmbd[1164]: [2026/08/26 15:27:01.245110, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Aug 26 15:27:01 volumio nmbd[1164]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Aug 26 15:27:01 volumio sudo[1179]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 26 15:27:01 volumio sudo[1179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:01 volumio sudo[1179]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:01 volumio sudo[1181]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 26 15:27:01 volumio sudo[1181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:01 volumio sudo[1181]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:01 volumio wireless.js[983]: WIRELESS.JS - INFO: Cleaning previous... Aug 26 15:27:01 volumio sudo[1184]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 26 15:27:01 volumio sudo[1184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:01 volumio systemd[1]: Received SIGRTMIN+21 from PID 455 (plymouthd). Aug 26 15:27:01 volumio systemd[1]: Received SIGRTMIN+21 from PID 455 (plymouthd). Aug 26 15:27:01 volumio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Aug 26 15:27:01 volumio systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Aug 26 15:27:01 volumio ifplugd[1075]: Network Interface Plugging Daemon...skip eth0...done. Aug 26 15:27:01 volumio loadcpufreq[1076]: Loading cpufreq kernel modules...done (acpi-cpufreq). Aug 26 15:27:01 volumio systemd[1]: Started getty@tty1.service - Getty on tty1. Aug 26 15:27:01 volumio systemd[1]: Reached target getty.target - Login Prompts. Aug 26 15:27:01 volumio systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Aug 26 15:27:01 volumio systemd[1]: Started loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling. Aug 26 15:27:01 volumio systemd[1]: Starting cpufrequtils.service - LSB: set CPUFreq kernel parameters... Aug 26 15:27:01 volumio cpufrequtils[1217]: CPUFreq Utilities: Setting ondemand CPUFreq governor...disabled, governor not available...done. Aug 26 15:27:01 volumio systemd[1]: Started cpufrequtils.service - LSB: set CPUFreq kernel parameters. Aug 26 15:27:01 volumio sudo[1184]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:01 volumio wireless.js[983]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 26 15:27:01 volumio wireless.js[983]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 1ms Aug 26 15:27:01 volumio wireless.js[983]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: ac:67:5d:04:59:07) Aug 26 15:27:01 volumio sudo[1230]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 26 15:27:01 volumio sudo[1230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:01 volumio sudo[1230]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:01 volumio sudo[1238]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 26 15:27:01 volumio sudo[1238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:01 volumio ntpd[1093]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:01 volumio ntpd[1093]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 26 15:27:01 volumio ntpd[1093]: DNS: dns_check: DNS error: -11, System error Aug 26 15:27:01 volumio ntpd[1093]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Aug 26 15:27:02 volumio ntpd[1093]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:02 volumio ntpd[1093]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 26 15:27:02 volumio ntpd[1093]: DNS: dns_check: DNS error: -11, System error Aug 26 15:27:02 volumio ntpd[1093]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Aug 26 15:27:03 volumio ntpd[1093]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:03 volumio ntpd[1093]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 26 15:27:03 volumio ntpd[1093]: DNS: dns_check: DNS error: -11, System error Aug 26 15:27:03 volumio ntpd[1093]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Aug 26 15:27:04 volumio systemd[1]: systemd-rfkill.service: Deactivated successfully. Aug 26 15:27:04 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Aug 26 15:27:04 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Aug 26 15:27:04 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Aug 26 15:27:04 volumio ntpd[1093]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:04 volumio ntpd[1093]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 26 15:27:04 volumio ntpd[1093]: DNS: dns_check: DNS error: -11, System error Aug 26 15:27:04 volumio ntpd[1093]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Aug 26 15:27:05 volumio volumio-remote-updater[982]: [2026-08-26 15:27:05] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 26 15:27:05 volumio volumio-remote-updater[982]: [2026-08-26 15:27:05] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 26 15:27:05 volumio volumio-remote-updater[982]: [2026-08-26 15:27:05] [error] handle_connect error: Connection refused Aug 26 15:27:06 volumio bash[1064]: setdatetime-helper: all HTTPS Date fallbacks failed Aug 26 15:27:06 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 26 15:27:06 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 26 15:27:11 volumio wireless.js[983]: WIRELESS.JS - INFO: Failed to determine most appropriate reg domain: Error: spawnSync /bin/sh ETIMEDOUT Aug 26 15:27:11 volumio wireless.js[983]: WIRELESS.JS - INFO: Start wireless flow Aug 26 15:27:11 volumio wireless.js[983]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Aug 26 15:27:11 volumio sudo[1276]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 26 15:27:11 volumio sudo[1276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:11 volumio sudo[1276]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:11 volumio sudo[1278]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 26 15:27:11 volumio sudo[1278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:11 volumio sudo[1278]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:11 volumio wireless.js[983]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 26 15:27:11 volumio wireless.js[983]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: ac:67:5d:04:59:07, USB: false) Aug 26 15:27:11 volumio wpa_supplicant[1284]: Successfully initialized wpa_supplicant Aug 26 15:27:12 volumio wpa_supplicant[1287]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=WORLD Aug 26 15:27:12 volumio sudo[1290]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 26 15:27:12 volumio sudo[1290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:12 volumio sudo[1290]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:12 volumio volumio-remote-updater[982]: [2026-08-26 15:27:12] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 26 15:27:12 volumio volumio-remote-updater[982]: [2026-08-26 15:27:12] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 26 15:27:12 volumio volumio-remote-updater[982]: [2026-08-26 15:27:12] [error] handle_connect error: Connection refused Aug 26 15:27:13 volumio wireless.js[983]: WIRELESS.JS - INFO: DHCP IP fallback Aug 26 15:27:13 volumio wireless.js[983]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Aug 26 15:27:13 volumio wireless.js[983]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Aug 26 15:27:13 volumio wireless.js[983]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> SCANNING (duration: 0ms) Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: SME: Trying to authenticate with 00:18:0a:83:e9:95 (SSID='Mullnet' freq=2412 MHz) Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=GB Aug 26 15:27:15 volumio kernel: wlan0: authenticate with 00:18:0a:83:e9:95 (local address=ac:67:5d:04:59:07) Aug 26 15:27:15 volumio kernel: wlan0: send auth to 00:18:0a:83:e9:95 (try 1/3) Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: Trying to associate with 00:18:0a:83:e9:95 (SSID='Mullnet' freq=2412 MHz) Aug 26 15:27:15 volumio sudo[1238]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:15 volumio kernel: wlan0: authenticated Aug 26 15:27:15 volumio kernel: wlan0: associate with 00:18:0a:83:e9:95 (try 1/3) Aug 26 15:27:15 volumio kernel: wlan0: RX AssocResp from 00:18:0a:83:e9:95 (capab=0x31 status=0 aid=14) Aug 26 15:27:15 volumio kernel: wlan0: associated Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: Associated with 00:18:0a:83:e9:95 Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: WPA: Key negotiation completed with 00:18:0a:83:e9:95 [PTK=CCMP GTK=CCMP] Aug 26 15:27:15 volumio wpa_supplicant[1287]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:18:0a:83:e9:95 completed [id=0 id_str=] Aug 26 15:27:15 volumio dhcpcd[1007]: wlan0: carrier acquired Aug 26 15:27:15 volumio dhcpcd[1007]: wlan0: connected to Access Point: Mullnet Aug 26 15:27:15 volumio dhcpcd[1007]: wlan0: IAID 5d:04:59:07 Aug 26 15:27:15 volumio dhcpcd[1007]: wlan0: adding address fe80::f443:d4d7:d319:c661 Aug 26 15:27:15 volumio dhcpcd[1007]: ipv6_addaddr1: Permission denied Aug 26 15:27:15 volumio wireless.js[983]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> COMPLETED (duration: 2018ms) Aug 26 15:27:15 volumio wireless.js[983]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Aug 26 15:27:15 volumio wireless.js[983]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to 00:18:0a:83:e9:95 Aug 26 15:27:15 volumio wireless.js[983]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Aug 26 15:27:15 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Aug 26 15:27:15 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 15:27:15 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 15:27:15 volumio upmpdcli[1332]: Could not open config: /tmp/upmpdcli.conf Aug 26 15:27:15 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:15 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 26 15:27:16 volumio dhcpcd[1007]: wlan0: soliciting an IPv6 router Aug 26 15:27:16 volumio sudo[1333]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Aug 26 15:27:16 volumio sudo[1333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:16 volumio dhcpcd[1007]: control command: /sbin/dhcpcd wlan0 Aug 26 15:27:16 volumio dhcpcd[1007]: control_free: No such file or directory Aug 26 15:27:16 volumio sudo[1333]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:16 volumio dhcpcd[1007]: wlan0: rebinding lease of 192.168.1.71 Aug 26 15:27:16 volumio dhcpcd[1007]: wlan0: probing address 192.168.1.71/24 Aug 26 15:27:18 volumio wireless.js[983]: WIRELESS.JS - INFO: Start ap Aug 26 15:27:18 volumio wireless.js[983]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 26 15:27:18 volumio systemd[1]: Started wireless.service - Wireless Services. Aug 26 15:27:18 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Aug 26 15:27:18 volumio systemd[1]: Started screenshot.service - Process screenshots triggered by PrtSc-button. Aug 26 15:27:18 volumio systemd[1]: Started soundcard-init.service - Intel SST and HDA soundcard init service. Aug 26 15:27:18 volumio systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk. Aug 26 15:27:18 volumio systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Aug 26 15:27:18 volumio volumio-cpu-tweak[1348]: Setting RT Priority for mpd Aug 26 15:27:18 volumio volumio-cpu-tweak[1382]: pid 35's current scheduling policy: SCHED_OTHER Aug 26 15:27:18 volumio volumio-cpu-tweak[1382]: pid 35's current scheduling priority: 0 Aug 26 15:27:18 volumio volumio-cpu-tweak[1348]: Setting MPD Affinity Aug 26 15:27:18 volumio volumio-cpu-tweak[1387]: pid 3's current affinity mask: ff Aug 26 15:27:18 volumio volumio-cpu-tweak[1348]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Aug 26 15:27:18 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Aug 26 15:27:18 volumio soundcard-init.sh[1421]: Card 0 Chip Realtek Generic Name HDA Intel PCH Aug 26 15:27:18 volumio soundcard-init.sh[1433]: Simple mixer control 'Master',0 Aug 26 15:27:18 volumio soundcard-init.sh[1433]: Capabilities: pvolume pvolume-joined pswitch pswitch-joined Aug 26 15:27:18 volumio soundcard-init.sh[1433]: Playback channels: Mono Aug 26 15:27:18 volumio soundcard-init.sh[1433]: Limits: Playback 0 - 87 Aug 26 15:27:18 volumio soundcard-init.sh[1433]: Mono: Playback 65 [75%] [-16.50dB] [on] Aug 26 15:27:18 volumio systemd[1]: soundcard-init.service: Deactivated successfully. Aug 26 15:27:18 volumio startx[1417]: X.Org X Server 1.21.1.7 Aug 26 15:27:18 volumio startx[1417]: X Protocol Version 11, Revision 0 Aug 26 15:27:18 volumio startx[1417]: Current Operating System: Linux volumio 6.12.57-volumio #2 SMP PREEMPT_DYNAMIC Thu Nov 13 17:08:37 CET 2025 x86_64 Aug 26 15:27:18 volumio startx[1417]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 bootdelay=5 biosdevname=0 imgpart=UUID=979bbeef-9f19-4327-b11b-8e461c9bb1fa bootpart=UUID=EA04-5FD3 datapart=UUID=bbfbcde0-94c9-4b89-8c57-b566bec99879 hwdevice=x86 uuidconfig=syslinux.cfg,efi/BOOT/grub.cfg imgfile=/volumio_current.sqsh logo.nologo vt.global_cursor_default=0 acpi_backlight=native net.ifnames=0 use_kmsg=no plymouth=0 video=efifb fbcon=rotate:0 Aug 26 15:27:18 volumio startx[1417]: xorg-server 2:21.1.7-3+deb12u11 (https://www.debian.org/support) Aug 26 15:27:18 volumio startx[1417]: Current version of pixman: 0.42.2 Aug 26 15:27:18 volumio startx[1417]: Before reporting problems, check http://wiki.x.org Aug 26 15:27:18 volumio startx[1417]: to make sure that you have the latest version. Aug 26 15:27:18 volumio startx[1417]: Markers: (--) probed, (**) from config file, (==) default setting, Aug 26 15:27:18 volumio startx[1417]: (++) from command line, (!!) notice, (II) informational, Aug 26 15:27:18 volumio startx[1417]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Aug 26 15:27:18 volumio startx[1417]: (==) Log file: "/var/log/Xorg.0.log", Time: Wed Aug 26 15:27:18 2026 Aug 26 15:27:18 volumio startx[1417]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Aug 26 15:27:19 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:19 volumio volumio[1343]: info: ----- Volumio3 ---- Aug 26 15:27:19 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:19 volumio volumio[1343]: info: ----- System startup ---- Aug 26 15:27:19 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:19 volumio volumio[1343]: info: MYVOLUMIO Environment detected Aug 26 15:27:19 volumio volumio[1343]: info: Plugin folders cleanup Aug 26 15:27:19 volumio volumio[1343]: info: Scanning into folder /volumio/app/plugins/ Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category audio_interface Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category miscellanea Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category music_service Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category plugins.json Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category system_controller Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category user_interface Aug 26 15:27:19 volumio volumio[1343]: info: Scanning into folder /data/plugins/ Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category music_service Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category system_hardware Aug 26 15:27:19 volumio volumio[1343]: info: Scanning category user_interface Aug 26 15:27:19 volumio volumio[1343]: info: Plugin folders cleanup completed Aug 26 15:27:19 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:19 volumio volumio[1343]: info: ----- Core plugins startup ---- Aug 26 15:27:19 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugins from folder /volumio/app/plugins/ Aug 26 15:27:19 volumio volumio[1343]: info: Adding plugin upnp to MyMusic Plugins Aug 26 15:27:19 volumio volumio[1343]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 26 15:27:19 volumio volumio[1343]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugins from folder /data/plugins/ Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "system"... Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "appearance"... Aug 26 15:27:19 volumio wireless.js[983]: WIRELESS.JS - INFO: trying... Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "network"... Aug 26 15:27:19 volumio volumio[1343]: info: Refreshing Cached IP Addresses Aug 26 15:27:19 volumio sudo[1467]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 15:27:19 volumio sudo[1467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:19 volumio sudo[1469]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:27:19 volumio sudo[1469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "services"... Aug 26 15:27:19 volumio sudo[1469]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "volumio5onboarding"... Aug 26 15:27:19 volumio sudo[1476]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 26 15:27:19 volumio sudo[1476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:19 volumio sudo[1467]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "alsa_controller"... Aug 26 15:27:19 volumio sudo[1497]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 26 15:27:19 volumio sudo[1497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:19 volumio sudo[1497]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:19 volumio sudo[1508]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:27:19 volumio sudo[1508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:19 volumio sudo[1508]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:19 volumio wireless.js[983]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 26 15:27:19 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "wizard"... Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "networkfs"... Aug 26 15:27:19 volumio volumio[1343]: info: Starting Udev Watcher for removable devices Aug 26 15:27:19 volumio volumio[1343]: info: Ignoring mount for partition: boot Aug 26 15:27:19 volumio volumio[1343]: info: Ignoring mount for partition: volumio Aug 26 15:27:19 volumio volumio[1343]: info: Ignoring mount for partition: volumio_data Aug 26 15:27:19 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "volumio_command_line_client"... Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "upnp"... Aug 26 15:27:19 volumio volumio[1343]: info: [1787754439632] Starting Upmpd Daemon Aug 26 15:27:19 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "my_music"... Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "mpd"... Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "upnp_browser"... Aug 26 15:27:19 volumio kernel: i915 0000:00:02.0: [drm] Reducing the compressed framebuffer size. This may lead to less power savings than a non-reduced-size. Try to increase stolen memory size if available in BIOS. Aug 26 15:27:19 volumio volumio[1343]: info: Starting UPNP Browser Aug 26 15:27:19 volumio volumio[1343]: info: Loading plugin "alarm-clock"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "airplay_emulation"... Aug 26 15:27:20 volumio volumio[1343]: info: Starting Shairport Sync Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "last_100"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "webradio"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "i2s_dacs"... Aug 26 15:27:20 volumio volumio[1343]: info: I2S DAC not set, start Auto-detection Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "volumiodiscovery"... Aug 26 15:27:20 volumio volumio[1343]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 15:27:20 volumio volumio[1343]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 15:27:20 volumio volumio[1343]: *** WARNING *** For more information see Aug 26 15:27:20 volumio volumio[1343]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 15:27:20 volumio volumio[1343]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 15:27:20 volumio node[1343]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 15:27:20 volumio volumio[1343]: *** WARNING *** For more information see Aug 26 15:27:20 volumio node[1343]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 15:27:20 volumio node[1343]: *** WARNING *** For more information see Aug 26 15:27:20 volumio node[1343]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 15:27:20 volumio node[1343]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 15:27:20 volumio node[1343]: *** WARNING *** For more information see Aug 26 15:27:20 volumio volumio[1343]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 26 15:27:20 volumio volumio[1343]: info: Discovery: Started advertising with name: Volumio Aug 26 15:27:20 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "spop"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "now_playing"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "outputs"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "albumart"... Aug 26 15:27:20 volumio volumio[1343]: info: Plugin example_plugin is not enabled Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "inputs"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "updater_comm"... Aug 26 15:27:20 volumio volumio[1607]: Forking 7 albumart workers Aug 26 15:27:20 volumio wireless.js[983]: WIRELESS.JS - INFO: trying... Aug 26 15:27:20 volumio volumio[1343]: info: Plugin mpdemulation is not enabled Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "rest_api"... Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "websocket"... Aug 26 15:27:20 volumio sudo[1694]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 26 15:27:20 volumio sudo[1694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:20 volumio volumio[1343]: info: Starting Socket.io Server version 1.7.4 Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "music_services_shield"... Aug 26 15:27:20 volumio sudo[1694]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:20 volumio sudo[1699]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:27:20 volumio sudo[1699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:20 volumio sudo[1699]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:20 volumio wireless.js[983]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 26 15:27:20 volumio volumio[1619]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1618]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1343]: info: Applying required configuration parameters for plugin music_services_shield Aug 26 15:27:20 volumio volumio[1617]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "Systeminfo"... Aug 26 15:27:20 volumio volumio[1620]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1643]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1630]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1621]: Starting albumart workers Aug 26 15:27:20 volumio volumio[1343]: info: Loading plugin "display_configuration"... Aug 26 15:27:21 volumio dhcpcd[1007]: wlan0: leased 192.168.1.71 for infinity Aug 26 15:27:21 volumio avahi-daemon[971]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.71. Aug 26 15:27:21 volumio volumio[1343]: info: Loading i18n strings for locale en Aug 26 15:27:21 volumio avahi-daemon[971]: New relevant interface wlan0.IPv4 for mDNS. Aug 26 15:27:21 volumio dhcpcd[1007]: wlan0: adding route to 192.168.1.0/24 Aug 26 15:27:21 volumio avahi-daemon[971]: Registering new address record for 192.168.1.71 on wlan0.IPv4. Aug 26 15:27:21 volumio dhcpcd[1007]: wlan0: adding default route via 192.168.1.1 Aug 26 15:27:21 volumio volumio[1343]: Updating browse sources language Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:27:21 volumio systemd[1]: welcome.service: Deactivated successfully. Aug 26 15:27:21 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 26 15:27:21 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 26 15:27:21 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 26 15:27:21 volumio welcome[1753]: Resolved ip:[1] 192.168.1.71 Aug 26 15:27:21 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 26 15:27:21 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::initPlayerControls Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio systemd[1]: Started nmbd.service - Samba NMB Daemon. Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: Express server listening on port 3000 Aug 26 15:27:21 volumio volumio[1343]: [Metrics] WebUI: 2s 264.22ms Aug 26 15:27:21 volumio volumio[1343]: info: Setting Device type: x86 Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::resetVolumioState Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::getcurrentVolume Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Aug 26 15:27:21 volumio volumio[1343]: info: Completed loading Core Plugins Aug 26 15:27:21 volumio volumio[1343]: info: Preparing to generate the ALSA configuration file Aug 26 15:27:21 volumio volumio[1343]: info: Volumio Network Manager: Network status updated: 0 Aug 26 15:27:21 volumio systemd[1]: Starting winbind.service - Samba Winbind Daemon... Aug 26 15:27:21 volumio volumio[1343]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Aug 26 15:27:21 volumio volumio[1343]: info: VolumeController:: Volume=49 Mute =false Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::pushState Aug 26 15:27:21 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioPushState Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::updateTrackBlock Aug 26 15:27:21 volumio volumio[1343]: info: CorePlayQueue::getTrackBlock Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 15:27:21 volumio volumio[1343]: info: Reloading queue from file Aug 26 15:27:21 volumio volumio[1343]: info: Asound.conf file unchanged, so no further update is needed Aug 26 15:27:21 volumio volumio[1343]: info: Output device has changed, restarting MPD Aug 26 15:27:21 volumio volumio[1343]: info: Output device has changed, restarting Shairport Sync Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio sudo[1797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 15:27:21 volumio sudo[1797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio sudo[1797]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio sudo[1799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 15:27:21 volumio sudo[1799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio volumio[1343]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 15:27:21 volumio systemd[1]: musicservicesshield.service: Deactivated successfully. Aug 26 15:27:21 volumio systemd[1]: Stopped musicservicesshield.service - Shield Volumio Music Services in the User CPU Set. Aug 26 15:27:21 volumio systemd[1]: Stopping musicservicesshield.service - Shield Volumio Music Services in the User CPU Set... Aug 26 15:27:21 volumio volumio[1343]: info: ___________ START PLUGINS ___________ Aug 26 15:27:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 15:27:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 15:27:21 volumio volumio[1343]: info: ControllerMpd::onStart: Initializing MPD Aug 26 15:27:21 volumio volumio[1343]: info: Creating MPD Configuration file Aug 26 15:27:21 volumio sudo[1816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 26 15:27:21 volumio sudo[1816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 15:27:21 volumio volumio[1343]: info: [1787754441328] CoreMusicLibrary::Adding element Media Servers Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:27:21 volumio sudo[1818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 15:27:21 volumio sudo[1818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio volumio[1343]: info: UPNP Browser: Client initialized successfully Aug 26 15:27:21 volumio sudo[1821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 15:27:21 volumio sudo[1818]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio sudo[1821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 15:27:21 volumio sudo[1816]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 26 15:27:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 26 15:27:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Aug 26 15:27:21 volumio volumio[1343]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 15:27:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 26 15:27:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 26 15:27:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Aug 26 15:27:21 volumio volumio[1343]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 15:27:21 volumio volumio[1343]: info: [1787754441355] CoreMusicLibrary::Adding element Last_100 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 15:27:21 volumio volumio[1343]: info: [1787754441356] CoreMusicLibrary::Adding element Webradio Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:27:21 volumio volumio[1343]: info: Initializing BBC Radios Aug 26 15:27:21 volumio volumio[1343]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: Creating Spotify config file Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio sudo[1834]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 15:27:21 volumio sudo[1834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:21 volumio sudo[1848]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 26 15:27:21 volumio sudo[1834]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio winbindd[1796]: [2026/08/26 15:27:21.427773, 0] ../../source3/winbindd/winbindd.c:1440(main) Aug 26 15:27:21 volumio winbindd[1796]: winbindd version 4.17.12-Debian started. Aug 26 15:27:21 volumio winbindd[1796]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Aug 26 15:27:21 volumio winbindd[1796]: [2026/08/26 15:27:21.437013, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache) Aug 26 15:27:21 volumio winbindd[1796]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 26 15:27:21 volumio systemd[1]: Started winbind.service - Samba Winbind Daemon. Aug 26 15:27:21 volumio systemd[1]: Starting smbd.service - Samba SMB Daemon... Aug 26 15:27:21 volumio volumio[1343]: info: [now-playing] ConfigUpdater: config is up to date. Aug 26 15:27:21 volumio volumio[1343]: info: Display-configuration --- loadI18nStrings: loading from /data/plugins/user_interface/display_configuration/i18n/strings_en.json Aug 26 15:27:21 volumio volumio[1343]: info: Display-configuration --- loadI18nStrings: loaded 54 keys Aug 26 15:27:21 volumio volumio[1343]: info: Volumio Calling Home Aug 26 15:27:21 volumio sudo[1894]: volumio : PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 26 15:27:21 volumio sudo[1894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio sudo[1899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/bash -c 'if [ -f /root/.Xauthority ]; then cp /root/.Xauthority /home/volumio/ && chown volumio:volumio /home/volumio/.Xauthority; fi' Aug 26 15:27:21 volumio sudo[1899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio wireless.js[983]: WIRELESS.JS - INFO: trying... Aug 26 15:27:21 volumio sudo[1899]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio sudo[1937]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 26 15:27:21 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio smbd[1880]: [2026/08/26 15:27:21.659480, 0] ../../source3/smbd/server.c:1741(main) Aug 26 15:27:21 volumio smbd[1880]: smbd version 4.17.12-Debian started. Aug 26 15:27:21 volumio smbd[1880]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Aug 26 15:27:21 volumio sudo[1940]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:27:21 volumio sudo[1940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:21 volumio sudo[1940]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio wireless.js[983]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.1.71, ipV6 is undefined Aug 26 15:27:21 volumio wireless.js[983]: WIRELESS.JS - INFO: Connected to SSID: Mullnet Aug 26 15:27:21 volumio wireless.js[983]: WIRELESS.JS - INFO: It's done! AP Aug 26 15:27:21 volumio volumio[1343]: info: [now-playing] App is listening on port 4004. Aug 26 15:27:21 volumio wireless.js[983]: WIRELESS.JS - INFO: Restarting avahi-daemon... Aug 26 15:27:21 volumio sudo[1945]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Aug 26 15:27:21 volumio sudo[1945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 26 15:27:21 volumio volumio[1343]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::setRepeat null single undefined Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::pushState Aug 26 15:27:21 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioPushState Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::setRandom null Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::pushState Aug 26 15:27:21 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioPushState Aug 26 15:27:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 15:27:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 15:27:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:21 volumio systemd[1]: shairport-sync.service: Consumed 1.839s CPU time. Aug 26 15:27:21 volumio avahi-daemon[971]: Got SIGTERM, quitting. Aug 26 15:27:21 volumio avahi-daemon[971]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.71. Aug 26 15:27:21 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 26 15:27:21 volumio avahi-daemon[971]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Restarting Browsing Aug 26 15:27:21 volumio avahi-daemon[971]: avahi-daemon 0.8 exiting. Aug 26 15:27:21 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Aug 26 15:27:21 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 26 15:27:21 volumio volumio[1343]: info: Display-configuration --- fixXauthority: /home/volumio/.Xauthority updated Aug 26 15:27:21 volumio volumio[1343]: info: MPD Permissions set Aug 26 15:27:21 volumio volumio[1343]: info: MPD Permissions set Aug 26 15:27:21 volumio dbus-daemon[973]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.14' (uid=1000 pid=1343 comm="/usr/bin/node /volumio/index.js") Aug 26 15:27:21 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 26 15:27:21 volumio avahi-daemon[1950]: Process 971 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Aug 26 15:27:21 volumio avahi-daemon[1950]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Aug 26 15:27:21 volumio avahi-daemon[1950]: Successfully dropped root privileges. Aug 26 15:27:21 volumio avahi-daemon[1950]: avahi-daemon 0.8 starting up. Aug 26 15:27:21 volumio dbus-daemon[973]: [system] Successfully activated service 'org.freedesktop.Avahi' Aug 26 15:27:21 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 26 15:27:21 volumio sudo[1945]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio sudo[1476]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio avahi-daemon[1950]: Successfully called chroot(). Aug 26 15:27:21 volumio avahi-daemon[1950]: Successfully dropped remaining capabilities. Aug 26 15:27:21 volumio avahi-daemon[1950]: No service file found in /etc/avahi/services. Aug 26 15:27:21 volumio avahi-daemon[1950]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.71. Aug 26 15:27:21 volumio avahi-daemon[1950]: New relevant interface wlan0.IPv4 for mDNS. Aug 26 15:27:21 volumio avahi-daemon[1950]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 26 15:27:21 volumio avahi-daemon[1950]: New relevant interface lo.IPv4 for mDNS. Aug 26 15:27:21 volumio avahi-daemon[1950]: Network interface enumeration completed. Aug 26 15:27:21 volumio avahi-daemon[1950]: Registering new address record for 192.168.1.71 on wlan0.IPv4. Aug 26 15:27:21 volumio avahi-daemon[1950]: Registering new address record for 127.0.0.1 on lo.IPv4. Aug 26 15:27:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:21 volumio volumio[1343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 26 15:27:21 volumio volumio[1343]: info: Spotify config file written Aug 26 15:27:21 volumio wireless.js[983]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 26 15:27:21 volumio sudo[1982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 15:27:21 volumio sudo[1982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio volumio[1343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 26 15:27:21 volumio volumio[1343]: info: VolumeController:: Volume=49 Mute =false Aug 26 15:27:21 volumio volumio[1343]: info: CoreStateMachine::pushState Aug 26 15:27:21 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioPushState Aug 26 15:27:21 volumio volumio[1343]: info: No need to fix Spotify hosts Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:21 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 26 15:27:21 volumio volumio5-onboarding[1825]: time=2026-08-26T15:27:21.839+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 26 15:27:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:21 volumio go-librespot[1992]: go-librespot daemon starting... Aug 26 15:27:21 volumio sudo[1982]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:21 volumio go-librespot[1998]: time="2026-08-26T15:27:21+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:21 volumio go-librespot[1998]: time="2026-08-26T15:27:21+01:00" level=debug msg="app state loaded" Aug 26 15:27:21 volumio go-librespot[1998]: time="2026-08-26T15:27:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:21 volumio volumio[1343]: 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: 3 Aug 26 15:27:21 volumio volumio[1343]: info: Starting Shairport Sync Aug 26 15:27:21 volumio volumio[1343]: info: Starting Shairport Sync Aug 26 15:27:21 volumio volumio[1343]: info: Starting Shairport Sync Aug 26 15:27:21 volumio sudo[2021]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 15:27:21 volumio sudo[2021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio sudo[2026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 15:27:21 volumio sudo[2024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 15:27:21 volumio sudo[2026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio sudo[2024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 15:27:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 15:27:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:21 volumio volumio[1343]: 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: 3 Aug 26 15:27:21 volumio volumio[1343]: error: Discovery: Advertisement error: Error: dns service error: unknown Aug 26 15:27:21 volumio volumio[1343]: error: Discovery: advertisement error: Error: dns service error: unknown Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Advertisement raised the following error Error: dns service error: unknown Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Stopping Advertising Immediately Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Stopping existing advertisement Aug 26 15:27:21 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:21 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:21 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:21 volumio volumio5-onboarding[1825]: time=2026-08-26T15:27:21.986+01:00 level=INFO msg="system info for da57f82018146d5fde17f5d350cf9d8f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 26 15:27:21 volumio systemd[1]: Started smbd.service - Samba SMB Daemon. Aug 26 15:27:21 volumio sudo[2021]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:21 volumio volumio[1343]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 26 15:27:22 volumio volumio[1343]: info: Discovery: Restarting Browsing Aug 26 15:27:22 volumio volumio[1343]: info: Discovery: Restart already pending, ignoring duplicate call Aug 26 15:27:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 26 15:27:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 26 15:27:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 26 15:27:22 volumio sudo[2026]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:22 volumio volumio[1343]: info: Shairport-Sync Started Aug 26 15:27:22 volumio volumio[1343]: Error adding Membership: Error: addMembership EINVAL Aug 26 15:27:22 volumio sudo[2024]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:22 volumio volumio[1343]: info: Shairport-Sync Started Aug 26 15:27:22 volumio volumio[1343]: info: Shairport-Sync Started Aug 26 15:27:22 volumio volumio5-onboarding[1825]: time=2026-08-26T15:27:22.021+01:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 26 15:27:22 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:22 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:22 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:22 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- X server ready after 1 attempt(s) Aug 26 15:27:22 volumio volumio[1343]: info: New Spotify access tokenBQBR04_ZhL... Aug 26 15:27:22 volumio volumio[1343]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Monitoring lid(s): /proc/acpi/button/lid/LID/state Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- DPMS disabled before playback state check Aug 26 15:27:22 volumio sudo[1894]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- xscreensaver cleaned up before starting Aug 26 15:27:22 volumio sudo[2085]: volumio : PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh Aug 26 15:27:22 volumio sudo[2085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Connected screens: eDP-1 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- No forced DRM orientation detected for eDP-1 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- TTY: display=normal(0) + offset=same(0) = 0 deg (fbconv=0) Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Plymouth: display=normal(0) + offset=same(0) = 0 deg Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Connected screens: eDP-1 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Rotation config saved for Grub: screen=eDP-1, plymouth=0, fbcon=0 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Panel Rotation applied via xrandr Aug 26 15:27:22 volumio sudo[2116]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/graphics/fbcon/rotate_all Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Runtime rotation applied: normal | Boot config (plymouth=0, fbconv=0) Aug 26 15:27:22 volumio sudo[2116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:22 volumio sudo[2116]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- fbcon console rotation set to 0 Aug 26 15:27:22 volumio volumio[1343]: SPOTIFY: User informations: {"account_id":"M9hvBbXamo","country":"GB","display_name":"kevmullet","email":"kevmullet@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/kevmullet"},"followers":{"href":null,"total":6},"href":"https://api.spotify.com/v1/users/kevmullet","id":"kevmullet","images":[],"product":"premium","type":"user","uri":"spotify:user:kevmullet"} Aug 26 15:27:22 volumio volumio[1343]: info: Spotify Successfully logged in Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 15:27:22 volumio volumio[1343]: info: [1787754442323] CoreMusicLibrary::Adding element Spotify Aug 26 15:27:22 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:27:22 volumio volumio[1343]: Cannot find translation for source Spotify Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=info msg="zeroconf server listening on port 33899" Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Connected screens: eDP-1 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Connected screens: eDP-1 Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="obtained new client token: AAE9HYUysyarng39oqu2gJplvHyZpfKTq1thiV7u2x3pyYzJ9tp9tavmNhudWdW1+II1MIsLf/m+/JUmN88hZx3Oq8Qb7fcPcyp9roPUjAz3V15yQ1EoMcu+WrwwhvqVKYkwce7zkyISqhAU/O46tyVxz1lOHhReC+CJs6Haer+NhVXYBx8XngQmoswstFHyvy998pLgaDZj37VNaYaTwOQd+ArmPS7PIo2jE6Tyk0FOorZ/3JPl8v4=" Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Touch-related devices detected: [{"id":"11","name":"⎜ ↳ Wacom HID 4910 Finger"}] Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Touch matrix: display=normal, offset=0, matrix=1 0 0 0 1 0 0 0 1 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Detected true physical resolution for eDP-1: 3000x2000 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Detected true physical resolution for eDP-1: 3000x2000 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Applying TV-safe overscan compensation=0% on eDP-1 (3000x2000) Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=debug msg="completed challenge" Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Using X11 scale+panning fallback Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- CMD: DISPLAY=:0 xrandr --output eDP-1 --mode 3000x2000 --scale 1.0000x1.0000 --panning 3000x2000 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Touch correction applied to ⎜ ↳ Wacom HID 4910 Finger (id=11) Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- applyPointerCorrection: pointer_offset=0 Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Pointer correction: none (xrandr handles relative devices) Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:22 volumio sudo[2153]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/backlight/intel_backlight/brightness Aug 26 15:27:22 volumio sudo[2153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:22 volumio sudo[2153]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- Brightness set to 100% (24000/24000) on intel_backlight Aug 26 15:27:22 volumio sudo[2150]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/pkill -9 -f unclutter Aug 26 15:27:22 volumio sudo[2150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:22 volumio volumio[1343]: info: Display-configuration --- No unclutter process to stop Aug 26 15:27:22 volumio sudo[2161]: volumio : PWD=/ ; USER=root ; ENV=DISPLAY=:0 ; COMMAND=/usr/bin/unclutter-xfixes -idle 3 Aug 26 15:27:22 volumio sudo[2161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:22 volumio avahi-daemon[1950]: Server startup complete. Host name is volumio.local. Local service cookie is 2435821040. Aug 26 15:27:22 volumio ntpd[1093]: IO: Listen normally on 3 wlan0 192.168.1.71:123 Aug 26 15:27:22 volumio ntpd[1093]: IO: new interface(s) found: waking up resolver Aug 26 15:27:22 volumio ntpd[1093]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:22 volumio go-librespot[1998]: time="2026-08-26T15:27:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:22 volumio ntpd[1093]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 26 15:27:22 volumio ntpd[1093]: DNS: Pool taking: 82.219.4.30 Aug 26 15:27:22 volumio ntpd[1093]: DNS: Pool taking: 178.215.228.24 Aug 26 15:27:22 volumio ntpd[1093]: DNS: Pool taking: 78.143.220.46 Aug 26 15:27:22 volumio ntpd[1093]: DNS: Pool taking: 131.111.8.60 Aug 26 15:27:22 volumio ntpd[1093]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Aug 26 15:27:22 volumio volumio-remote-updater[982]: [2026-08-26 15:27:22] [connect] Successful connection Aug 26 15:27:22 volumio volumio-remote-updater[982]: [2026-08-26 15:27:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787754442 101 Aug 26 15:27:22 volumio volumio[1343]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Aug 26 15:27:23 volumio ntpd[1093]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:23 volumio ntpd[1093]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 185.137.221.158 Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 45.154.197.21 Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 45.138.55.60 Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 193.57.144.50 Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 2a12:bec4:1821:56d::123 Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 2a00:da00:f474:fd00:0:110:: Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 2a01:7e00::f03c:94ff:fee2:c5ff Aug 26 15:27:23 volumio ntpd[1093]: DNS: Pool taking: 2a10:3781:2d18::33 Aug 26 15:27:23 volumio ntpd[1093]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Aug 26 15:27:23 volumio mpd[1849]: 2026-08-26T15:27:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 15:27:23 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 26 15:27:23 volumio sudo[1821]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:23 volumio sudo[1799]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:23 volumio volumio[1343]: info: Completed starting Core Plugins Aug 26 15:27:23 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:23 volumio volumio[1343]: info: ----- MyVolumio plugins startup ---- Aug 26 15:27:23 volumio volumio[1343]: info: ------------------------------------------- Aug 26 15:27:23 volumio volumio[1343]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 15:27:23 volumio volumio[1343]: error: MPD error: The expression evaluated to a falsy value: Aug 26 15:27:23 volumio volumio[1343]: assert.ok(self.idling) Aug 26 15:27:23 volumio volumio[1343]: error: The expression evaluated to a falsy value: Aug 26 15:27:23 volumio volumio[1343]: assert.ok(self.idling) Aug 26 15:27:23 volumio volumio[1343]: error: updateQueue error: null Aug 26 15:27:23 volumio volumio[1343]: info: MPD running with PID1849 Aug 26 15:27:23 volumio volumio[1343]: ,establishing connection Aug 26 15:27:23 volumio volumio[1343]: error: updateQueue error: null Aug 26 15:27:23 volumio systemd[1]: Starting musicservicesshield.service - Shield Volumio Music Services in the User CPU Set... Aug 26 15:27:23 volumio bash[2280]: mount: /cpusets: unknown filesystem type 'cpuset'. Aug 26 15:27:23 volumio bash[2280]: dmesg(1) may have more information after failed mount system call. Aug 26 15:27:23 volumio bash[2286]: mount: /cpusets: unknown filesystem type 'cpuset'. Aug 26 15:27:23 volumio bash[2286]: dmesg(1) may have more information after failed mount system call. Aug 26 15:27:24 volumio bash[2292]: mount: /cpusets: unknown filesystem type 'cpuset'. Aug 26 15:27:24 volumio bash[2292]: dmesg(1) may have more information after failed mount system call. Aug 26 15:27:24 volumio bash[2290]: cset: **> mount of cpuset filesystem failed, do you have permission? Aug 26 15:27:24 volumio systemd[1]: Finished musicservicesshield.service - Shield Volumio Music Services in the User CPU Set. Aug 26 15:27:24 volumio systemd[1]: Reached target multi-user.target - Multi-User System. Aug 26 15:27:24 volumio systemd[1]: Reached target graphical.target - Graphical Interface. Aug 26 15:27:24 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Aug 26 15:27:24 volumio systemd[1]: Reloading. Aug 26 15:27:24 volumio volumio[1343]: info: Display-configuration --- Kiosk browser detected after 1s, re-applying input settings in 3s Aug 26 15:27:24 volumio systemd-gpt-auto-generator[2305]: EFI loader partition unknown, exiting. Aug 26 15:27:24 volumio systemd-gpt-auto-generator[2305]: (The boot loader did not set EFI variable LoaderDevicePartUUID.) Aug 26 15:27:24 volumio volumio[1343]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Aug 26 15:27:24 volumio systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal Aug 26 15:27:24 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:24 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:24 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:27:24 volumio sudo[2085]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:24 volumio volumio[1343]: info: succeeded Aug 26 15:27:24 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Aug 26 15:27:24 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Aug 26 15:27:24 volumio systemd[1]: Startup finished in 6.353s (firmware) + 1.150s (loader) + 12.928s (kernel) + 26.459s (userspace) = 46.891s. Aug 26 15:27:24 volumio volumio[1343]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:24 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 15:27:24 volumio volumio[1343]: info: Listing playlists Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 15:27:24 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:27:24 volumio ntpd[1093]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:24 volumio volumio[1343]: info: go-librespot daemon successfully initialized Aug 26 15:27:25 volumio ntpd[1093]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 90.155.12.14 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 31.121.161.188 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 85.199.214.101 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 178.79.155.116 Aug 26 15:27:25 volumio ntpd[1093]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Aug 26 15:27:25 volumio ntpd[1093]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 26 15:27:25 volumio ntpd[1093]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool skipping: 85.199.214.101 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 139.162.242.115 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 90.155.12.13 Aug 26 15:27:25 volumio ntpd[1093]: DNS: Pool taking: 185.57.191.229 Aug 26 15:27:25 volumio ntpd[1093]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 26 15:27:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 15:27:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:26 volumio go-librespot[2320]: go-librespot daemon starting... Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="app state loaded" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=info msg="zeroconf server listening on port 46275" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="obtained new client token: AAE66IioypxjFqe5xx3AxVLmhWAlmuaalyQSIbhsns8qnMrG4xCWHtIiu8IxZkMEsH5YCitRXqei8LfKJ4YXdylO8IRt2Wpc83YTkK9YfxC4l1LT6z3GEhMkCilb7R8fbWzI9XrzK5LL/5S/GmR31MyPUsKyDQdCZEmRu4UcNf/GWnbYLXrOV3qx6ykkIzPrszjkEUP2gbesET/8hFonFZppL8DEi5Ji7Jd53tcnEBgy7h+S0mUvfZI=" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=debug msg="completed challenge" Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:26 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:27:26 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:26 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:26 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:26 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:26 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:26 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:26 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:26 volumio go-librespot[2321]: time="2026-08-26T15:27:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:26 volumio volumio[1343]: info: Volumio called home Aug 26 15:27:26 volumio volumio[1343]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 26 15:27:26 volumio volumio[1343]: info: Discovery: Restarting Browsing Aug 26 15:27:26 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 26 15:27:26 volumio volumio[1343]: info: Discovery: Restarting Advertising Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- Connected screens: eDP-1 Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- Touch-related devices detected: [{"id":"11","name":"⎜ ↳ Wacom HID 4910 Finger"}] Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- Touch matrix: display=normal, offset=0, matrix=1 0 0 0 1 0 0 0 1 Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- Touch correction applied to ⎜ ↳ Wacom HID 4910 Finger (id=11) Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- applyPointerCorrection: pointer_offset=0 Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- Pointer correction: none (xrandr handles relative devices) Aug 26 15:27:27 volumio volumio[1343]: info: Display-configuration --- Input settings re-applied after kiosk start Aug 26 15:27:27 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:27:27 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:27 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:27 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:27 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:27 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:27 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:27 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:27 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 26 15:27:27 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:27 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:28 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Aug 26 15:27:36 volumio ntpd[1093]: CLOCK: time stepped by 7.388586 Aug 26 15:27:36 volumio ntpd[1093]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes Aug 26 15:27:36 volumio volumio[1343]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 15:27:36 volumio volumio[1343]: info: Volumio Network Manager: Network status updated: 2 Aug 26 15:27:37 volumio sudo[2363]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 15:27:37 volumio sudo[2363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:37 volumio sudo[2365]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:27:37 volumio sudo[2365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:37 volumio sudo[2365]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:37 volumio sudo[2369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 26 15:27:37 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:37 volumio sudo[2363]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 15:27:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:37 volumio go-librespot[2373]: go-librespot daemon starting... Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="app state loaded" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=info msg="zeroconf server listening on port 38163" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="obtained new client token: AAGD6H+astAB0zoBDh11NqCcs21+iWkpQK1QAF2PwvToEx821go+wx766wwPqe/OCPhWQU/nN8wpWcNGVy8JE2jTsGjov7P6mnHuM7VuL4rtwTIZ0Zrcmnv8bQ3GholMcDCYr0iJpDnzaRMe4gynLlreC4DB1t+tTbO2RTr96JYHQZxtLW4sw/EbZHq6FuqajRpMrFBZCsQ3Cm5d5auo8uVxn2uiCsiZjEjBoSv9g/KRetBnItKp" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=debug msg="completed challenge" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:37 volumio go-librespot[2375]: time="2026-08-26T15:27:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:37 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Aug 26 15:27:38 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:38 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:38 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Aug 26 15:27:38 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 15:27:38 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 26 15:27:38 volumio sudo[2369]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:38 volumio volumio[1343]: info: Upmpdcli Daemon Started Aug 26 15:27:39 volumio volumio[1343]: info: Discovery: Started advertising with name: Volumio Aug 26 15:27:39 volumio upmpdcli[2410]: writing RSA key Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin bluetooth to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin multiroom to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin metavolumio to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin cd_controller to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 26 15:27:39 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:39 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:39 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:39 volumio volumio[1343]: info: Starting MyVolumio Remote Streaming Endpoints Aug 26 15:27:39 volumio volumio[1343]: info: MyVolumio login type: Token Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 26 15:27:39 volumio volumio[1343]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 26 15:27:40 volumio volumio[1343]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 26 15:27:40 volumio volumio[1343]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 26 15:27:40 volumio volumio[1343]: info: Streaming services startup Aug 26 15:27:40 volumio volumio[1343]: info: Starting Streaming Daemon Aug 26 15:27:40 volumio sudo[2417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 26 15:27:40 volumio sudo[2417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:40 volumio volumio[1343]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 26 15:27:40 volumio sudo[2417]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:40 volumio volumio[1343]: error: Cannot start Volumio Streaming Daemon Aug 26 15:27:40 volumio volumio[1343]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 15:27:40 volumio volumio[1343]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: adding b3b87f11-bc70-4b76-89bc-b4f80384f7b2 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: Found device Volumio Aug 26 15:27:40 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:40 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: this is already registered, b3b87f11-bc70-4b76-89bc-b4f80384f7b2 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: Found device Volumio Aug 26 15:27:40 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:40 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: this is already registered, b3b87f11-bc70-4b76-89bc-b4f80384f7b2 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: Found device Volumio Aug 26 15:27:40 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:40 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: this is already registered, b3b87f11-bc70-4b76-89bc-b4f80384f7b2 Aug 26 15:27:40 volumio volumio[1343]: info: Discovery: Found device Volumio Aug 26 15:27:40 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:40 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:40 volumio volumio[1343]: error: MyVolumio Custom Token format not valid, refreshing it Aug 26 15:27:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 26 15:27:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:40 volumio go-librespot[2428]: go-librespot daemon starting... Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=debug msg="app state loaded" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=info msg="zeroconf server listening on port 33665" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:40 volumio volumio[1343]: info: MyVolumio login type: Token Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=debug msg="obtained new client token: AAGPB0V+7CHrYOEoOPIgh6yBFGBqIdnwaFKggLDgewJKXZqzxUmKwqhWjUfv1aghDAav7S6no4Sn9dToIaYJkk/YBZGow0+qLZzumfZ2Nc4jEuik8aIvoFw7xYxWehCb1JgYA7I4Ryixr5EyZUzNttxsfWQHkkUWkRXh0pGprB4zxeWbgL9SE1kz3a9hkulc02prSpS5ewN9iRVqeIzztSTZ4cS23xS838ccARdFVtwoTrx8wTEH668=" Aug 26 15:27:40 volumio go-librespot[2429]: time="2026-08-26T15:27:40+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 26 15:27:41 volumio go-librespot[2429]: time="2026-08-26T15:27:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 26 15:27:41 volumio go-librespot[2429]: time="2026-08-26T15:27:41+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:41 volumio go-librespot[2429]: time="2026-08-26T15:27:41+01:00" level=debug msg="completed challenge" Aug 26 15:27:41 volumio go-librespot[2429]: time="2026-08-26T15:27:41+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:41 volumio go-librespot[2429]: time="2026-08-26T15:27:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:41 volumio volumio[1343]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 26 15:27:41 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:41 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:41 volumio volumio[1343]: info: MyVolumio token set successfully Aug 26 15:27:41 volumio volumio[1343]: info: MYVOLUMIO: Adding device Aug 26 15:27:41 volumio volumio[1343]: info: MYVOLUMIO: Evaluating Server Aug 26 15:27:41 volumio volumio[1343]: info: MyVolumio status changed Aug 26 15:27:41 volumio volumio[1343]: info: Streaming services startup Aug 26 15:27:41 volumio volumio[1343]: info: Starting Streaming Daemon Aug 26 15:27:41 volumio volumio[1343]: info: Removing browser output: myVolumio user plan is not superstar Aug 26 15:27:41 volumio volumio[1343]: info: Removing audio output: Aug 26 15:27:41 volumio volumio[1343]: info: Stoppping Tunnel 1 Aug 26 15:27:41 volumio sudo[2463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 26 15:27:41 volumio sudo[2463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:41 volumio sudo[2465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 26 15:27:41 volumio sudo[2465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:27:41 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:41 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:41 volumio sudo[2463]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:41 volumio volumio[1343]: error: Cannot start Volumio Streaming Daemon Aug 26 15:27:41 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:41 volumio volumio[1343]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 26 15:27:41 volumio volumio[1343]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 26 15:27:41 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:41 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:41 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 26 15:27:41 volumio sudo[2465]: pam_unix(sudo:session): session closed for user root Aug 26 15:27:41 volumio volumio[1343]: info: Remote SSH Stopped Aug 26 15:27:42 volumio volumio[1343]: info: Setting Geolocation for MyVolumio to eu3 Aug 26 15:27:42 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:42 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:42 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:42 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:42 volumio volumio[1343]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 26 15:27:43 volumio volumio[1343]: info: Updating MyVolumio device info Aug 26 15:27:43 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:43 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:43 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:43 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:43 volumio volumio[1343]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 26 15:27:44 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:44 volumio volumio[1343]: info: Systeminfo: --[object Object] Aug 26 15:27:44 volumio volumio[1343]: info: Systeminfo web UI listening on port 12334 Aug 26 15:27:44 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:44 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 26 15:27:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:44 volumio go-librespot[2471]: go-librespot daemon starting... Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="app state loaded" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=info msg="zeroconf server listening on port 36097" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="obtained new client token: AAEBm+agipxVjAsGiDy/I5W9DjacEbv3oJ3F5K3T01ZjjALS1x5n89VI5FljDnzvG0Y7VFQZDCFOQ0z4r6kHtIojr2QC/+9cr+qsMAcsicvOF0omdU5Kywbg4UN/miT7LqO578L+fnQQy4s65D3QdwT5VbgJFtb2hRx0vdLySia/p3nSGQ922aLmWL/cFZJ/lAZZlLQ2AjsioK/njAfuZFedP5Q3X70V84GIeJ+0f/wws7n2bnnDfuU=" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=debug msg="completed challenge" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:44 volumio go-librespot[2472]: time="2026-08-26T15:27:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:46 volumio volumio[1343]: info: MYVOLUMIO: Adding device Aug 26 15:27:46 volumio volumio[1343]: info: MYVOLUMIO: Evaluating Server Aug 26 15:27:47 volumio volumio[1343]: info: Setting Geolocation for MyVolumio to eu3 Aug 26 15:27:47 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:47 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:47 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:47 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:47 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:47 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:47 volumio volumio[1343]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 26 15:27:48 volumio volumio[1343]: info: Updating MyVolumio device info Aug 26 15:27:48 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:48 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:48 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:48 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 26 15:27:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:48 volumio go-librespot[2521]: go-librespot daemon starting... Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="app state loaded" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=info msg="zeroconf server listening on port 39555" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:48 volumio volumio[1343]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="obtained new client token: AAEdHrHYHa3349neSm+QbHkgZuFXdI/YZEIXQBeSVx29qslYeZ9gsYKkcYwHOuqQ4eYNSOXit1EwopskqQoPojbZ0ApyjJ387cRI2C+nqfPFTcSokFzgVgdwD/TWQVurFMZ78P05hm5jndQgLsgAIL7phuwnSRfPj6wTc+iGy+cSu21HAb2BqUJzf11XCObNG16V708TAsVJgdJzP3ooi3FrW9Sq9FM0YvZbST3Ic7GKngEu6AFmtJc=" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=debug msg="completed challenge" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:48 volumio go-librespot[2522]: time="2026-08-26T15:27:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:27:50 volumio volumio[1343]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 26 15:27:50 volumio volumio[1343]: info: Received Get System Version Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:27:50 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:50 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:50 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:50 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:50 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:50 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 26 15:27:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:51 volumio go-librespot[2537]: go-librespot daemon starting... Aug 26 15:27:51 volumio go-librespot[2538]: time="2026-08-26T15:27:51+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:51 volumio go-librespot[2538]: time="2026-08-26T15:27:51+01:00" level=debug msg="app state loaded" Aug 26 15:27:51 volumio go-librespot[2538]: time="2026-08-26T15:27:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=info msg="zeroconf server listening on port 43257" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="obtained new client token: AAGK1IGDAyNW/bCCMrYzoahAOj6RjLNuhFEjuLJx/6INecuBqMNi81AK14+iMNUezpEeAU14/PRZ1dS9AybBSiUA78OvY/tcZiADOLY6zwTlSBB5xtHCsg3XqPaR/L7+2egSdxdxWSlBN/fWCPigSsQdwuAudYyTg7vTKZl8wuwMz5DVko1UShCtWcGrFunaCH821oEkgxjgCNmDmAgaFuM+Ix1EckfM086S2a9ysyeVFz02dFin" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=debug msg="completed challenge" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:52 volumio go-librespot[2538]: time="2026-08-26T15:27:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:53 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:53 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:54 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 26 15:27:54 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:27:54 volumio volumio[1343]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 26 15:27:54 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:54 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 26 15:27:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:55 volumio go-librespot[2570]: go-librespot daemon starting... Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="app state loaded" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=info msg="zeroconf server listening on port 44789" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="obtained new client token: AAE36krgfvUYUjdRf3adzlqsIY8U49zxVlYHSI5HDnUQ94KohTXHdt6pILYozUJYWKoiJB7F6It94rKRyBwyvoWhdBNb4Nwhsp0B8hZVJGStz90Z2arPR93yjA5f6wkmwotoKeqw8i2UXgeZU4gkZAouKAQ38iLT3nfOYuEnc1a5+GuH7VoMMM+4K0shE95nmFae4M7I6LaK+HWQDyEBXT9VYOxscLyzxomQJDZgsRvjIUyKltroLk0=" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=debug msg="completed challenge" Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:55 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 26 15:27:55 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 26 15:27:55 volumio go-librespot[2571]: time="2026-08-26T15:27:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:56 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:56 volumio volumio[1343]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:27:58 volumio volumio[1343]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Aug 26 15:27:58 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:58 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:27:58 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:27:58 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 15:27:58 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 26 15:27:58 volumio volumio-remote-updater[982]: Test mode disabled Aug 26 15:27:58 volumio volumio-remote-updater[982]: Alpha mode disabled Aug 26 15:27:58 volumio volumio-remote-updater[982]: Alpha legacy test mode disabled Aug 26 15:27:59 volumio volumio[1343]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:27:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 26 15:27:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:27:59 volumio go-librespot[2614]: go-librespot daemon starting... Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="app state loaded" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=info msg="zeroconf server listening on port 43345" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:27:59 volumio volumio[1343]: info: Initializing connection to go-librespot Websocket Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="new websocket client" Aug 26 15:27:59 volumio volumio[1343]: info: Connection to go-librespot Websocket established Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="obtained new client token: AAE5wYUQQlwSoFZeTm9ntXPQa8w9FHwICD51EiNTFZoHO9ep+8gGeOVzajd3BzZCqsVYpJHeTCq1wEGN7GRCaRUjiHGS1dgUwMhtdiVZ/MK1ZyRYBE0GttD3FhN6nX/QEcUxeufnKZpqGzvjc2/6CinRfy/HhCZNnUl0IB15k9S1SnuqxSFRFVuTDVueX0/z8aNvdWs2ylvpFNxev5d4YXsboJVQ10TlpDEJn6Q7RjUVsrFL2ZDNDz0=" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 26 15:27:59 volumio volumio5-onboarding[1825]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Aug 26 15:27:59 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:59 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="completed keyexchange" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=debug msg="completed challenge" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=info msg="authenticated AP" username="ke*****et" Aug 26 15:27:59 volumio go-librespot[2615]: time="2026-08-26T15:27:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:27:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:27:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:27:59 volumio volumio[1343]: info: Connection to go-librespot Websocket closed Aug 26 15:27:59 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 26 15:27:59 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 15:27:59 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 26 15:27:59 volumio volumio5-onboarding[2628]: time=2026-08-26T15:27:59.602+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 26 15:27:59 volumio volumio[1343]: 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: 7 Aug 26 15:27:59 volumio volumio[1343]: 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: 7 Aug 26 15:27:59 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:59 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:59 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:59 volumio volumio5-onboarding[2628]: time=2026-08-26T15:27:59.607+01:00 level=INFO msg="system info for da57f82018146d5fde17f5d350cf9d8f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 26 15:27:59 volumio volumio5-onboarding[2628]: time=2026-08-26T15:27:59.620+01:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 26 15:27:59 volumio volumio[1343]: info: Received Get System Info Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:27:59 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:27:59 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:27:59 volumio volumio-remote-updater[982]: Test mode disabled Aug 26 15:27:59 volumio volumio-remote-updater[982]: Alpha mode disabled Aug 26 15:27:59 volumio volumio-remote-updater[982]: Alpha legacy test mode disabled Aug 26 15:27:59 volumio volumio[1343]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::volumioGetBrowseSources Aug 26 15:27:59 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:28:00 volumio volumio[1343]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 26 15:28:00 volumio volumio[1343]: info: Completed starting MyVolumio Plugin Aug 26 15:28:00 volumio volumio[1343]: [Metrics] CommandRouter: 33s 507.29ms Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::volumiosetStartupVolume Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::Close All Modals sent Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::Close All Modals sent Aug 26 15:28:00 volumio volumio5-onboarding[2628]: time=2026-08-26T15:28:00.053+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 26 15:28:00 volumio volumio5-onboarding[2628]: time=2026-08-26T15:28:00.054+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 26 15:28:00 volumio volumio5-onboarding[2628]: time=2026-08-26T15:28:00.054+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:28:00 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 26 15:28:01 volumio volumio5-onboarding[2628]: time=2026-08-26T15:28:01.081+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=V6rxnx3Jw3RxPpJp7fw2KthddsJ3 tokenExpiry=2026-08-26T16:28:01.081+01:00 Aug 26 15:28:01 volumio volumio[1343]: info: Received Get System Info Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:28:01 volumio volumio[1343]: info: Discovery: Getting this device information Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::volumioGetState Aug 26 15:28:01 volumio volumio[1343]: info: CorePlayQueue::getTrack 0 Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 15:28:01 volumio volumio[1343]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 15:28:01 volumio volumio5-onboarding[2628]: time=2026-08-26T15:28:01.804+01:00 level=INFO msg="enabling local network discovery" Aug 26 15:28:01 volumio volumio5-onboarding[2628]: time=2026-08-26T15:28:01.807+01:00 level=INFO msg="enabling BLE discovery" Aug 26 15:28:02 volumio volumio[1343]: info: Getting Spotify volume Aug 26 15:28:02 volumio volumio[1343]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 15:28:02 volumio volumio[1343]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:28:02 volumio volumio[1343]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 15:28:02 volumio volumio[1343]: errno: -111, Aug 26 15:28:02 volumio volumio[1343]: code: 'ECONNREFUSED', Aug 26 15:28:02 volumio volumio[1343]: syscall: 'connect', Aug 26 15:28:02 volumio volumio[1343]: address: '127.0.0.1', Aug 26 15:28:02 volumio volumio[1343]: port: 9879, Aug 26 15:28:02 volumio volumio[1343]: response: undefined Aug 26 15:28:02 volumio volumio[1343]: } Aug 26 15:28:02 volumio volumio[1343]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 15:28:02 volumio sudo[2667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 15:27' Aug 26 15:28:02 volumio sudo[2667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"