Oct 15 17:21:00 volumio-acer systemd-journald[571]: Runtime Journal (/run/log/journal/30175a60cf76629f74f78d9769c2cd99) is 3.7M, max 30.0M, 26.2M free. Oct 15 17:21:00 volumio-acer systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... Oct 15 17:21:00 volumio-acer systemd-journald[571]: Received client request to flush runtime journal. Oct 15 17:21:00 volumio-acer systemd[1]: systemd-machine-id-commit.service - Commit a transient machine-id on disk was skipped because of an unmet condition check (ConditionPathIsMountPoint=/etc/machine-id). Oct 15 17:21:00 volumio-acer systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Oct 15 17:21:00 volumio-acer systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 15 17:21:00 volumio-acer systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 704 (systemd-binfmt) Oct 15 17:21:00 volumio-acer systemd[1]: Received SIGRTMIN+20 from PID 424 (plymouthd). Oct 15 17:21:00 volumio-acer systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. Oct 15 17:21:00 volumio-acer systemd[1]: Finished plymouth-rotation.service - Plymouth rotation detection for shutdown/reboot. Oct 15 17:21:00 volumio-acer systemd[1]: Starting plymouth-start.service - Show Plymouth Boot Screen... Oct 15 17:21:00 volumio-acer systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 15 17:21:00 volumio-acer systemd[1]: Started haveged.service - Entropy Daemon based on the HAVEGE algorithm. Oct 15 17:21:00 volumio-acer sh[721]: command failed: No such device (-19) Oct 15 17:21:00 volumio-acer systemd[1]: Starting rpcbind.service - RPC bind portmap service... Oct 15 17:21:00 volumio-acer systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Oct 15 17:21:00 volumio-acer systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Oct 15 17:21:00 volumio-acer systemd[1]: Started plymouth-start.service - Show Plymouth Boot Screen. Oct 15 17:21:00 volumio-acer systemd[1]: systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch was skipped because of an unmet condition check (ConditionPathExists=!/run/plymouth/pid). Oct 15 17:21:00 volumio-acer systemd[1]: Started systemd-ask-password-plymouth.path - Forward Password Requests to Plymouth Directory Watch. Oct 15 17:21:00 volumio-acer systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 15 17:21:00 volumio-acer systemd[1]: Started rpcbind.service - RPC bind portmap service. Oct 15 17:21:00 volumio-acer systemd[1]: Reached target rpcbind.target - RPC Port Mapper. Oct 15 17:21:00 volumio-acer kernel: ath: phy0: ASPM enabled: 0x42 Oct 15 17:21:00 volumio-acer kernel: ath: EEPROM regdomain: 0x65 Oct 15 17:21:00 volumio-acer kernel: ath: EEPROM indicates we should expect a direct regpair map Oct 15 17:21:00 volumio-acer kernel: ath: Country alpha2 being used: 00 Oct 15 17:21:00 volumio-acer kernel: ath: Regpair used: 0x65 Oct 15 17:21:00 volumio-acer systemd[1]: Starting systemd-rfkill.service - Load/Save RF Kill Switch Status... Oct 15 17:21:00 volumio-acer kernel: ieee80211 phy0: Selected rate control algorithm 'minstrel_ht' Oct 15 17:21:00 volumio-acer kernel: ieee80211 phy0: Atheros AR9287 Rev:2 mem=0x000000008825818a, irq=17 Oct 15 17:21:00 volumio-acer (udev-worker)[612]: Network interface NamePolicy= disabled on kernel command line. Oct 15 17:21:00 volumio-acer systemd[1]: Started systemd-rfkill.service - Load/Save RF Kill Switch Status. Oct 15 17:21:00 volumio-acer haveged[726]: haveged: command socket is listening at fd 3 Oct 15 17:21:00 volumio-acer systemd[1]: Expecting device sys-subsystem-net-devices-wlan0.device - /sys/subsystem/net/devices/wlan0... Oct 15 17:21:00 volumio-acer systemd[1]: Found device sys-subsystem-net-devices-wlan0.device - AR9287 Wireless Network Adapter (PCI-Express). Oct 15 17:21:00 volumio-acer systemd[1]: Started ifup@wlan0.service - ifup for wlan0. Oct 15 17:21:00 volumio-acer kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Oct 15 17:21:00 volumio-acer (udev-worker)[618]: pcmC5D0p: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Oct 15 17:21:00 volumio-acer systemd[1]: Finished ifupdown-pre.service - Helper to synchronize boot up for ifupdown. Oct 15 17:21:00 volumio-acer systemd[1]: Starting networking.service - Raise network interfaces... Oct 15 17:21:00 volumio-acer sh[810]: eth0=eth0 Oct 15 17:21:00 volumio-acer sh[836]: wlan0=wlan0 Oct 15 17:21:00 volumio-acer haveged[726]: haveged: ver: 1.9.14; arch: x86; vend: GenuineIntel; build: (gcc 12.2.0 ITV); collect: 128K Oct 15 17:21:00 volumio-acer haveged[726]: haveged: cpu: (L4 VC); data: 32K (L4 V); inst: 32K (L4 V); idx: 24/40; sz: 32010/53875 Oct 15 17:21:00 volumio-acer haveged[726]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00089 Oct 15 17:21:00 volumio-acer haveged[726]: haveged: fills: 0, generated: 0 Oct 15 17:21:00 volumio-acer systemd[1]: Finished networking.service - Raise network interfaces. Oct 15 17:21:01 volumio-acer systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... Oct 15 17:21:01 volumio-acer systemd[1]: Mounting run-rpc_pipefs.mount - RPC Pipe File System... Oct 15 17:21:01 volumio-acer systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. Oct 15 17:21:01 volumio-acer systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target sysinit.target - System Initialization. Oct 15 17:21:01 volumio-acer systemd[1]: Started acpid.path - ACPI Events Check. Oct 15 17:21:01 volumio-acer systemd[1]: Started apt-daily.timer - Daily apt download activities. Oct 15 17:21:01 volumio-acer systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. Oct 15 17:21:01 volumio-acer systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. Oct 15 17:21:01 volumio-acer systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. Oct 15 17:21:01 volumio-acer systemd[1]: Started fstrim.timer - Discard unused blocks once a week. Oct 15 17:21:01 volumio-acer systemd[1]: Started man-db.timer - Daily man-db regeneration. Oct 15 17:21:01 volumio-acer systemd[1]: Started ntpsec-rotate-stats.timer - Rotate ntpd stats daily. Oct 15 17:21:01 volumio-acer systemd[1]: Started setdatetime-helper.timer - Volumio Time Sync Watchdog Timer. Oct 15 17:21:01 volumio-acer systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target paths.target - Path Units. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target timers.target - Timer Units. Oct 15 17:21:01 volumio-acer systemd[1]: Listening on acpid.socket - ACPID Listen Socket. Oct 15 17:21:01 volumio-acer systemd[1]: Listening on avahi-daemon.socket - Avahi mDNS/DNS-SD Stack Activation Socket. Oct 15 17:21:01 volumio-acer systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target sockets.target - Socket Units. Oct 15 17:21:01 volumio-acer systemd[1]: systemd-pcrphase-sysinit.service - TPM2 PCR Barrier (Initialization) was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f). Oct 15 17:21:01 volumio-acer systemd[1]: Reached target basic.target - Basic System. Oct 15 17:21:01 volumio-acer systemd[1]: Started acpid.service - ACPI event daemon. Oct 15 17:21:01 volumio-acer systemd[1]: alsa-state.service - Manage Sound Card State (restore and store) was skipped because of an unmet condition check (ConditionPathExists=/etc/alsa/state-daemon.conf). Oct 15 17:21:01 volumio-acer systemd[1]: Starting alsa-restore.service - Save/Restore Sound Card State... Oct 15 17:21:01 volumio-acer systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Oct 15 17:21:01 volumio-acer systemd[1]: Starting dbus.service - D-Bus System Message Bus... Oct 15 17:21:01 volumio-acer systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... Oct 15 17:21:01 volumio-acer systemd[1]: getty-static.service - getty on tty2-tty6 if dbus and logind are not available was skipped because of an unmet condition check (ConditionPathExists=!/usr/bin/dbus-daemon). Oct 15 17:21:01 volumio-acer systemd[1]: headless_wireless.service - Copy user wpa_supplicant.conf was skipped because of an unmet condition check (ConditionPathExists=/boot/wpa_supplicant.conf). Oct 15 17:21:01 volumio-acer systemd[1]: Starting dhcpcd.service - DHCP Client Daemon on all interfaces... Oct 15 17:21:01 volumio-acer systemd[1]: Started iptables.service - Volumio Iptables Module. Oct 15 17:21:01 volumio-acer systemd[1]: Starting systemd-logind.service - User Login Management... Oct 15 17:21:01 volumio-acer systemd[1]: Starting triggerhappy.service - triggerhappy global hotkey daemon... Oct 15 17:21:01 volumio-acer systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 15 17:21:01 volumio-acer systemd[1]: Started volumio-remote-updater.service - Volumio Remote OTA Updater. Oct 15 17:21:01 volumio-acer systemd[1]: volumiossh.service - Volumio SSH enabler was skipped because of an unmet condition check (ConditionPathExistsGlob=/boot/ssh{,.txt}). Oct 15 17:21:01 volumio-acer systemd[1]: Starting wireless.service - Wireless Services... Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Successfully dropped root privileges. Oct 15 17:21:01 volumio-acer avahi-daemon[882]: avahi-daemon 0.8 starting up. Oct 15 17:21:01 volumio-acer kernel: RPC: Registered named UNIX socket transport module. Oct 15 17:21:01 volumio-acer kernel: RPC: Registered udp transport module. Oct 15 17:21:01 volumio-acer kernel: RPC: Registered tcp transport module. Oct 15 17:21:01 volumio-acer kernel: RPC: Registered tcp-with-tls transport module. Oct 15 17:21:01 volumio-acer kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Oct 15 17:21:01 volumio-acer systemd[1]: Mounted run-rpc_pipefs.mount - RPC Pipe File System. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target rpc_pipefs.target. Oct 15 17:21:01 volumio-acer 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). Oct 15 17:21:01 volumio-acer systemd[1]: Reached target nfs-client.target - NFS client services. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 15 17:21:01 volumio-acer systemd[1]: Starting loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling... Oct 15 17:21:01 volumio-acer 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). Oct 15 17:21:01 volumio-acer systemd[1]: Finished alsa-restore.service - Save/Restore Sound Card State. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target sound.target - Sound Card. Oct 15 17:21:01 volumio-acer thd[888]: Unable to parse trigger line: Oct 15 17:21:01 volumio-acer thd[888]: Unable to parse trigger line: Oct 15 17:21:01 volumio-acer thd[888]: Device /dev/input/event5 not suitable. Oct 15 17:21:01 volumio-acer acpid[880]: starting up with netlink and the input layer Oct 15 17:21:01 volumio-acer systemd[1]: e2scrub_reap.service: Deactivated successfully. Oct 15 17:21:01 volumio-acer systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. Oct 15 17:21:01 volumio-acer systemd[1]: Started triggerhappy.service - triggerhappy global hotkey daemon. Oct 15 17:21:01 volumio-acer acpid[880]: 3 rules loaded Oct 15 17:21:01 volumio-acer acpid[880]: waiting for events: event logging is off Oct 15 17:21:01 volumio-acer systemd[1]: Starting th-udev-rebind.service - Late rebind of input devices to triggerhappy... Oct 15 17:21:01 volumio-acer dhcpcd[885]: dhcpcd-9.4.1 starting Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event0 to thd using --add... Oct 15 17:21:01 volumio-acer systemd-logind[887]: New seat seat0. Oct 15 17:21:01 volumio-acer systemd-logind[887]: Watching system buttons on /dev/input/event2 (Power Button) Oct 15 17:21:01 volumio-acer systemd-logind[887]: Watching system buttons on /dev/input/event0 (Lid Switch) Oct 15 17:21:01 volumio-acer systemd-logind[887]: Watching system buttons on /dev/input/event1 (Sleep Button) Oct 15 17:21:01 volumio-acer systemd-logind[887]: Watching system buttons on /dev/input/event3 (AT Translated Set 2 keyboard) Oct 15 17:21:01 volumio-acer systemd-logind[887]: Watching system buttons on /dev/input/event16 (Acer WMI hotkeys) Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event1 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event10 to thd using --add... Oct 15 17:21:01 volumio-acer dhcpcd[909]: dev: loaded udev Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event11 to thd using --add... Oct 15 17:21:01 volumio-acer volumio-remote-updater[890]: Volumio OTA Client: 1.7.0 Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event12 to thd using --add... Oct 15 17:21:01 volumio-acer dhcpcd[909]: DUID 00:04:40:b7:7e:70:0c:3f:e0:11:9e:3f:bd:57:db:0b:07:a1 Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event13 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event14 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event15 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event16 to thd using --add... Oct 15 17:21:01 volumio-acer volumio-remote-updater[890]: Error: No active session Oct 15 17:21:01 volumio-acer volumio-remote-updater[890]: [2026-10-15 17:21:01] [info] asio async_connect error: asio.system:111 (Connection refused) Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event2 to thd using --add... Oct 15 17:21:01 volumio-acer volumio-remote-updater[890]: [2026-10-15 17:21:01] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Oct 15 17:21:01 volumio-acer volumio-remote-updater[890]: [2026-10-15 17:21:01] [error] handle_connect error: Connection refused Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event3 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event4 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event5 to thd using --add... Oct 15 17:21:01 volumio-acer thd[888]: Device /dev/input/event5 not suitable. Oct 15 17:21:01 volumio-acer kernel: 8021q: 802.1Q VLAN Support v1.8 Oct 15 17:21:01 volumio-acer systemd[1]: Started dhcpcd.service - DHCP Client Daemon on all interfaces. Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event6 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event7 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event8 to thd using --add... Oct 15 17:21:01 volumio-acer th-udev-rebind.sh[905]: Rebinding /dev/input/event9 to thd using --add... Oct 15 17:21:01 volumio-acer systemd[1]: th-udev-rebind.service: Deactivated successfully. Oct 15 17:21:01 volumio-acer systemd[1]: Finished th-udev-rebind.service - Late rebind of input devices to triggerhappy. Oct 15 17:21:01 volumio-acer upmpdcli[889]: Could not open config: /tmp/upmpdcli.conf Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Successfully called chroot(). Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Successfully dropped remaining capabilities. Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Loading service file /services/volumio.service. Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Oct 15 17:21:01 volumio-acer avahi-daemon[882]: New relevant interface lo.IPv4 for mDNS. Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Network interface enumeration completed. Oct 15 17:21:01 volumio-acer avahi-daemon[882]: Registering new address record for 127.0.0.1 on lo.IPv4. Oct 15 17:21:01 volumio-acer loadcpufreq[896]: Loading cpufreq kernel modules...done (acpi-cpufreq). Oct 15 17:21:01 volumio-acer systemd[1]: Started dbus.service - D-Bus System Message Bus. Oct 15 17:21:01 volumio-acer systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 15 17:21:01 volumio-acer systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 15 17:21:01 volumio-acer systemd[1]: Started loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling. Oct 15 17:21:01 volumio-acer systemd[1]: iptables.service: Deactivated successfully. Oct 15 17:21:01 volumio-acer dbus-daemon[883]: [system] Successfully activated service 'org.freedesktop.systemd1' Oct 15 17:21:01 volumio-acer systemd[1]: Starting cpufrequtils.service - LSB: set CPUFreq kernel parameters... Oct 15 17:21:01 volumio-acer systemd[1]: Starting wpa_supplicant.service - WPA supplicant... Oct 15 17:21:01 volumio-acer systemd[1]: Started systemd-logind.service - User Login Management. Oct 15 17:21:01 volumio-acer systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Oct 15 17:21:01 volumio-acer dhcpcd[909]: eth0: waiting for carrier Oct 15 17:21:01 volumio-acer dhcpcd[909]: dhcpcd_prestartinterface: Operation not possible due to RF-kill Oct 15 17:21:01 volumio-acer dhcpcd[909]: wlan0: waiting for carrier Oct 15 17:21:01 volumio-acer cpufrequtils[988]: CPUFreq Utilities: Setting ondemand CPUFreq governor...disabled, governor not available...done. Oct 15 17:21:01 volumio-acer systemd[1]: Started cpufrequtils.service - LSB: set CPUFreq kernel parameters. Oct 15 17:21:01 volumio-acer systemd[1]: Started wpa_supplicant.service - WPA supplicant. Oct 15 17:21:01 volumio-acer wpa_supplicant[991]: Successfully initialized wpa_supplicant Oct 15 17:21:01 volumio-acer systemd[1]: Reached target network.target - Network. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target network-online.target - Network is Online. Oct 15 17:21:01 volumio-acer systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically... Oct 15 17:21:01 volumio-acer systemd[1]: Starting nmbd.service - Samba NMB Daemon... Oct 15 17:21:01 volumio-acer systemd[1]: Starting ntpsec.service - Network Time Service... Oct 15 17:21:01 volumio-acer systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... Oct 15 17:21:01 volumio-acer systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart... Oct 15 17:21:01 volumio-acer systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon... Oct 15 17:21:01 volumio-acer sm-notify[1007]: Version 2.6.2 starting Oct 15 17:21:01 volumio-acer systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 15 17:21:01 volumio-acer systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 17:21:01 volumio-acer systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Oct 15 17:21:01 volumio-acer systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Oct 15 17:21:01 volumio-acer systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor. Oct 15 17:21:01 volumio-acer systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 15 17:21:01 volumio-acer systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. Oct 15 17:21:01 volumio-acer systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart. Oct 15 17:21:01 volumio-acer ntpd[1017]: INIT: ntpd ntpsec-1.2.2: Starting Oct 15 17:21:01 volumio-acer ntp-systemd-wrapper[1017]: 2026-10-15T17:21:01 ntpd[1017]: INIT: ntpd ntpsec-1.2.2: Starting Oct 15 17:21:01 volumio-acer ntp-systemd-wrapper[1017]: 2026-10-15T17:21:01 ntpd[1017]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Oct 15 17:21:01 volumio-acer ntpd[1017]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Oct 15 17:21:01 volumio-acer ntpd[1031]: INIT: precision = 0.107 usec (-23) Oct 15 17:21:01 volumio-acer systemd[1]: Started ntpsec.service - Network Time Service. Oct 15 17:21:01 volumio-acer systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Oct 15 17:21:01 volumio-acer welcome[1023]: Resolved ip:[0] Oct 15 17:21:01 volumio-acer ntpd[1031]: INIT: successfully locked into RAM Oct 15 17:21:01 volumio-acer ifplugd(eth0)[1048]: ifplugd 0.28 initializing. Oct 15 17:21:01 volumio-acer ntpd[1031]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf Oct 15 17:21:01 volumio-acer ifplugd(eth0)[1048]: Using interface eth0/20:6A:8A:32:9A:92 with driver (version: 6.12.57-volumio) Oct 15 17:21:01 volumio-acer ifplugd(eth0)[1048]: Using detection mode: SIOCETHTOOL Oct 15 17:21:01 volumio-acer ifplugd(eth0)[1048]: Initialization complete, link beat not detected. Oct 15 17:21:01 volumio-acer ntpd[1031]: CONFIG: restrict nopeer ignored Oct 15 17:21:01 volumio-acer systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... Oct 15 17:21:01 volumio-acer systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Oct 15 17:21:01 volumio-acer ntpd[1031]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 15 17:21:01 volumio-acer ntpd[1031]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2026-06-28T00:00Z last=2017-01-01T00:00Z ofs=37 Oct 15 17:21:01 volumio-acer ntpd[1031]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 110 days ago Oct 15 17:21:01 volumio-acer ntpd[1031]: INIT: Using SO_TIMESTAMPNS(ns) Oct 15 17:21:01 volumio-acer ntpd[1031]: IO: Listen and drop on 0 v6wildcard [::]:123 Oct 15 17:21:01 volumio-acer ntpd[1031]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 15 17:21:01 volumio-acer ntpd[1031]: IO: Listen normally on 2 lo 127.0.0.1:123 Oct 15 17:21:01 volumio-acer ntpd[1031]: IO: Listening on routing socket on fd #19 for interface updates Oct 15 17:21:01 volumio-acer systemd[1]: Received SIGRTMIN+21 from PID 424 (plymouthd). Oct 15 17:21:01 volumio-acer systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 15 17:21:01 volumio-acer ntpd[1031]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes Oct 15 17:21:01 volumio-acer ntpd[1031]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090 Oct 15 17:21:01 volumio-acer ntpd[1031]: INIT: Running with OpenSSL 3.0.18 30 Sep 2025, 30000120 Oct 15 17:21:01 volumio-acer ntpd[1031]: NTSc: Using system default root certificates. Oct 15 17:21:01 volumio-acer sshd[1055]: Server listening on 0.0.0.0 port 22. Oct 15 17:21:01 volumio-acer systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Oct 15 17:21:01 volumio-acer sshd[1055]: Server listening on :: port 22. Oct 15 17:21:01 volumio-acer systemd[1]: Received SIGRTMIN+21 from PID 424 (plymouthd). Oct 15 17:21:01 volumio-acer systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Oct 15 17:21:01 volumio-acer systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Oct 15 17:21:01 volumio-acer ifplugd[1002]: Network Interface Plugging Daemon...start eth0...done. Oct 15 17:21:01 volumio-acer ntpd[1031]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory Oct 15 17:21:01 volumio-acer systemd[1]: Started getty@tty1.service - Getty on tty1. Oct 15 17:21:01 volumio-acer systemd[1]: Reached target getty.target - Login Prompts. Oct 15 17:21:01 volumio-acer systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Oct 15 17:21:02 volumio-acer avahi-daemon[882]: Server startup complete. Host name is volumio-acer.local. Local service cookie is 1016087012. Oct 15 17:21:02 volumio-acer systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Oct 15 17:21:02 volumio-acer systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Oct 15 17:21:02 volumio-acer nmbd[1085]: [2026/10/15 17:21:02.449230, 0] ../../source3/nmbd/nmbd.c:901(main) Oct 15 17:21:02 volumio-acer nmbd[1085]: nmbd version 4.17.12-Debian started. Oct 15 17:21:02 volumio-acer nmbd[1085]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 15 17:21:02 volumio-acer nmbd[1085]: [2026/10/15 17:21:02.454129, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Oct 15 17:21:02 volumio-acer nmbd[1085]: started asyncdns process 1088 Oct 15 17:21:02 volumio-acer nmbd[1085]: [2026/10/15 17:21:02.454898, 0] ../../lib/util/become_daemon.c:150(daemon_status) Oct 15 17:21:02 volumio-acer nmbd[1085]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Oct 15 17:21:02 volumio-acer nmbd[1085]: [2026/10/15 17:21:02.455380, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Oct 15 17:21:02 volumio-acer nmbd[1085]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Oct 15 17:21:02 volumio-acer sudo[1107]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 15 17:21:02 volumio-acer sudo[1107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:02 volumio-acer sudo[1107]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer sudo[1109]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 15 17:21:02 volumio-acer sudo[1109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:02 volumio-acer sudo[1109]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Cleaning previous... Oct 15 17:21:02 volumio-acer sudo[1112]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 15 17:21:02 volumio-acer sudo[1112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:02 volumio-acer sudo[1112]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: ensureInterfaceReady: ifconfig up failed: Error: Command failed: /usr/bin/sudo /sbin/ifconfig wlan0 up Oct 15 17:21:02 volumio-acer wireless.js[891]: SIOCSIFFLAGS: Operation not possible due to RF-kill Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 2ms Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 20:7c:8f:59:95:df) Oct 15 17:21:02 volumio-acer sudo[1119]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 15 17:21:02 volumio-acer sudo[1119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:02 volumio-acer sudo[1119]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer sudo[1127]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 15 17:21:02 volumio-acer sudo[1127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:02 volumio-acer sudo[1127]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer wireless.js[891]: command failed: Network is down (-100) Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: netconfigured file not found, starting hotspot Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 1ms Oct 15 17:21:02 volumio-acer ntpd[1031]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:02 volumio-acer ntpd[1031]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 15 17:21:02 volumio-acer ntpd[1031]: DNS: dns_check: DNS error: -11, System error Oct 15 17:21:02 volumio-acer ntpd[1031]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Oct 15 17:21:02 volumio-acer sudo[1138]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 15 17:21:02 volumio-acer sudo[1138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:02 volumio-acer sudo[1138]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer sudo[1140]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 15 17:21:02 volumio-acer sudo[1140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:02 volumio-acer sudo[1140]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:02 volumio-acer systemd[1]: Starting hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... Oct 15 17:21:02 volumio-acer systemd[1]: welcome.service: Deactivated successfully. Oct 15 17:21:02 volumio-acer systemd[1]: Stopped welcome.service - Show a welcome message on console. Oct 15 17:21:02 volumio-acer systemd[1]: Stopping welcome.service - Show a welcome message on console... Oct 15 17:21:02 volumio-acer systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 15 17:21:02 volumio-acer welcome[1149]: Resolved ip:[0] Oct 15 17:21:02 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Notified systemd about wireless ready Oct 15 17:21:02 volumio-acer iwconfig[1153]: Error for wireless request "Set Power Management" (8B2C) : Oct 15 17:21:02 volumio-acer iwconfig[1153]: SET failed on device wlan0 ; Operation not supported. Oct 15 17:21:02 volumio-acer systemd[1]: Started wireless.service - Wireless Services. Oct 15 17:21:02 volumio-acer systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 15 17:21:02 volumio-acer systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Oct 15 17:21:02 volumio-acer systemd[1]: Started volumio.service - Volumio Backend Module. Oct 15 17:21:02 volumio-acer systemd[1]: Started screenshot.service - Process screenshots triggered by PrtSc-button. Oct 15 17:21:02 volumio-acer systemd[1]: Started soundcard-init.service - Intel SST and HDA soundcard init service. Oct 15 17:21:02 volumio-acer systemd[1]: Started volumio-kiosk.service - Start Volumio Kiosk. Oct 15 17:21:02 volumio-acer systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Oct 15 17:21:02 volumio-acer hostapd[1148]: rfkill: WLAN hard blocked Oct 15 17:21:02 volumio-acer hostapd[1148]: Failed to set beacon parameters Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: Could not connect to kernel driver Oct 15 17:21:02 volumio-acer hostapd[1148]: Interface initialization failed Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: interface state UNINITIALIZED->DISABLED Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: AP-DISABLED Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: Unable to setup interface. Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: interface state DISABLED->DISABLED Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: AP-DISABLED Oct 15 17:21:02 volumio-acer hostapd[1148]: wlan0: CTRL-EVENT-TERMINATING Oct 15 17:21:02 volumio-acer hostapd[1148]: hostapd_free_hapd_data: Interface wlan0 wasn't started Oct 15 17:21:02 volumio-acer hostapd[1148]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Oct 15 17:21:02 volumio-acer systemd[1]: hostapd.service: Control process exited, code=exited, status=1/FAILURE Oct 15 17:21:02 volumio-acer systemd[1]: hostapd.service: Failed with result 'exit-code'. Oct 15 17:21:02 volumio-acer systemd[1]: Failed to start hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Oct 15 17:21:02 volumio-acer systemd[1]: Starting dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... Oct 15 17:21:02 volumio-acer systemd[1]: Cannot find unit for notify message of PID 1145, ignoring. Oct 15 17:21:02 volumio-acer volumio-cpu-tweak[1168]: Setting RT Priority for mpd Oct 15 17:21:02 volumio-acer volumio-cpu-tweak[1189]: pid 35's current scheduling policy: SCHED_OTHER Oct 15 17:21:02 volumio-acer volumio-cpu-tweak[1189]: pid 35's current scheduling priority: 0 Oct 15 17:21:02 volumio-acer volumio-cpu-tweak[1168]: Setting MPD Affinity Oct 15 17:21:02 volumio-acer volumio-cpu-tweak[1195]: pid 3's current affinity mask: f Oct 15 17:21:02 volumio-acer volumio-cpu-tweak[1168]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Oct 15 17:21:02 volumio-acer avahi-daemon[882]: Service "Volumio-acer" (/services/volumio.service) successfully established. Oct 15 17:21:02 volumio-acer systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Oct 15 17:21:02 volumio-acer dnsmasq[1243]: started, version 2.90 cachesize 150 Oct 15 17:21:02 volumio-acer dnsmasq[1243]: compile time options: IPv6 GNU-getopt DBus no-UBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth cryptohash DNSSEC loop-detect inotify dumpfile Oct 15 17:21:02 volumio-acer dnsmasq-dhcp[1243]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Oct 15 17:21:02 volumio-acer dnsmasq[1243]: reading /etc/resolv.conf Oct 15 17:21:02 volumio-acer dnsmasq[1243]: using nameserver 192.168.31.1#53 Oct 15 17:21:02 volumio-acer dnsmasq[1243]: using nameserver 223.5.5.5#53 Oct 15 17:21:02 volumio-acer dnsmasq[1243]: read /etc/hosts - 4 names Oct 15 17:21:02 volumio-acer systemd[1]: Started dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. Oct 15 17:21:02 volumio-acer systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 15 17:21:03 volumio-acer soundcard-init.sh[1237]: Card 0 Chip Nvidia GPU 14 HDMI/DP Name HDA NVidia Oct 15 17:21:03 volumio-acer startx[1233]: X.Org X Server 1.21.1.7 Oct 15 17:21:03 volumio-acer startx[1233]: X Protocol Version 11, Revision 0 Oct 15 17:21:03 volumio-acer startx[1233]: Current Operating System: Linux volumio-acer 6.12.57-volumio #2 SMP PREEMPT_DYNAMIC Thu Nov 13 17:08:37 CET 2025 x86_64 Oct 15 17:21:03 volumio-acer startx[1233]: Kernel command line: BOOT_IMAGE=/vmlinuz initramfs.clear splash plymouth.ignore-serial-consoles quiet loglevel=0 bootdelay=5 biosdevname=0 imgpart=UUID=989265ff-d248-4f89-8e52-b7555c637af2 bootpart=UUID=DDF4-322F datapart=UUID=e4183fc1-3cea-4235-aefc-fb12bf1a152b 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 Oct 15 17:21:03 volumio-acer startx[1233]: xorg-server 2:21.1.7-3+deb12u11 (https://www.debian.org/support) Oct 15 17:21:03 volumio-acer startx[1233]: Current version of pixman: 0.42.2 Oct 15 17:21:03 volumio-acer startx[1233]: Before reporting problems, check http://wiki.x.org Oct 15 17:21:03 volumio-acer startx[1233]: to make sure that you have the latest version. Oct 15 17:21:03 volumio-acer startx[1233]: Markers: (--) probed, (**) from config file, (==) default setting, Oct 15 17:21:03 volumio-acer startx[1233]: (++) from command line, (!!) notice, (II) informational, Oct 15 17:21:03 volumio-acer startx[1233]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Oct 15 17:21:03 volumio-acer startx[1233]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Oct 15 17:21:03 2026 Oct 15 17:21:03 volumio-acer startx[1233]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Oct 15 17:21:03 volumio-acer soundcard-init.sh[1237]: Card 1 Chip Realtek Generic Name HDA Intel PCH Oct 15 17:21:03 volumio-acer soundcard-init.sh[1264]: Simple mixer control 'Master',0 Oct 15 17:21:03 volumio-acer soundcard-init.sh[1264]: Capabilities: pvolume pvolume-joined pswitch pswitch-joined Oct 15 17:21:03 volumio-acer soundcard-init.sh[1264]: Playback channels: Mono Oct 15 17:21:03 volumio-acer soundcard-init.sh[1264]: Limits: Playback 0 - 87 Oct 15 17:21:03 volumio-acer soundcard-init.sh[1264]: Mono: Playback 65 [75%] [-16.50dB] [on] Oct 15 17:21:03 volumio-acer soundcard-init.sh[1237]: Card 5 Chip USB Mixer Name YSHIFI-F801 Oct 15 17:21:03 volumio-acer systemd[1]: soundcard-init.service: Deactivated successfully. Oct 15 17:21:03 volumio-acer kernel: i915 0000:00:02.0: vgaarb: VGA decodes changed: olddecodes=io+mem,decodes=none:owns=io+mem Oct 15 17:21:03 volumio-acer kernel: nouveau 0000:01:00.0: vgaarb: VGA decodes changed: olddecodes=io+mem,decodes=none:owns=none Oct 15 17:21:03 volumio-acer systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Oct 15 17:21:03 volumio-acer systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Oct 15 17:21:03 volumio-acer systemd[1]: welcome.service: Deactivated successfully. Oct 15 17:21:03 volumio-acer systemd[1]: Stopped welcome.service - Show a welcome message on console. Oct 15 17:21:03 volumio-acer systemd[1]: Stopping welcome.service - Show a welcome message on console... Oct 15 17:21:03 volumio-acer systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 15 17:21:03 volumio-acer welcome[1279]: Resolved ip:[0] Oct 15 17:21:03 volumio-acer systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 15 17:21:03 volumio-acer systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Oct 15 17:21:03 volumio-acer dhcpcd[909]: eth0: carrier acquired Oct 15 17:21:03 volumio-acer kernel: tg3 0000:04:00.0 eth0: Link is up at 1000 Mbps, full duplex Oct 15 17:21:03 volumio-acer kernel: tg3 0000:04:00.0 eth0: Flow control is on for TX and on for RX Oct 15 17:21:03 volumio-acer kernel: tg3 0000:04:00.0 eth0: EEE is enabled Oct 15 17:21:03 volumio-acer dhcpcd[909]: eth0: IAID 8a:32:9a:92 Oct 15 17:21:03 volumio-acer dhcpcd[909]: eth0: adding address fe80::4df9:c673:4c73:57eb Oct 15 17:21:03 volumio-acer dhcpcd[909]: ipv6_addaddr1: Permission denied Oct 15 17:21:03 volumio-acer dhcpcd[909]: eth0: probing address 192.168.31.148/24 Oct 15 17:21:03 volumio-acer ifplugd(eth0)[1048]: Link beat detected. Oct 15 17:21:03 volumio-acer ntpd[1031]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:03 volumio-acer ntpd[1031]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 15 17:21:03 volumio-acer ntpd[1031]: DNS: dns_check: DNS error: -11, System error Oct 15 17:21:03 volumio-acer ntpd[1031]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Oct 15 17:21:03 volumio-acer ifplugd(eth0)[1048]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Oct 15 17:21:03 volumio-acer ifplugd(eth0)[1048]: client: ifup: interface eth0 already configured Oct 15 17:21:03 volumio-acer ifplugd(eth0)[1048]: Program executed successfully. Oct 15 17:21:04 volumio-acer dhcpcd[909]: eth0: soliciting an IPv6 router Oct 15 17:21:04 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:04 volumio-acer volumio[1156]: info: ----- Volumio3 ---- Oct 15 17:21:04 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:04 volumio-acer volumio[1156]: info: ----- System startup ---- Oct 15 17:21:04 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:04 volumio-acer kernel: nouveau 0000:01:00.0: drm: [DRM/00000001:kmsOutp] [LOAD_DETECT data:00000154] load:07 (ret:7) Oct 15 17:21:04 volumio-acer volumio[1156]: info: MYVOLUMIO Environment detected Oct 15 17:21:04 volumio-acer kernel: nouveau 0000:01:00.0: drm: [DRM/00000001:kmsOutp] [LOAD_DETECT data:00000154] load:07 (ret:7) Oct 15 17:21:04 volumio-acer volumio[1156]: info: Plugin folders cleanup Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning into folder /volumio/app/plugins/ Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category audio_interface Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category miscellanea Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category music_service Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category plugins.json Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category system_controller Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category user_interface Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning into folder /data/plugins/ Oct 15 17:21:04 volumio-acer volumio[1156]: info: Scanning category user_interface Oct 15 17:21:04 volumio-acer volumio[1156]: info: Plugin folders cleanup completed Oct 15 17:21:04 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:04 volumio-acer volumio[1156]: info: ----- Core plugins startup ---- Oct 15 17:21:04 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:04 volumio-acer volumio[1156]: info: Loading plugins from folder /volumio/app/plugins/ Oct 15 17:21:04 volumio-acer volumio[1156]: info: Adding plugin upnp to MyMusic Plugins Oct 15 17:21:04 volumio-acer volumio[1156]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 15 17:21:04 volumio-acer volumio[1156]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 15 17:21:04 volumio-acer volumio[1156]: info: Loading plugins from folder /data/plugins/ Oct 15 17:21:04 volumio-acer volumio[1156]: info: Loading plugin "system"... Oct 15 17:21:04 volumio-acer volumio[1156]: info: Loading plugin "appearance"... Oct 15 17:21:04 volumio-acer ntpd[1031]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:04 volumio-acer ntpd[1031]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 15 17:21:04 volumio-acer ntpd[1031]: DNS: dns_check: DNS error: -11, System error Oct 15 17:21:04 volumio-acer ntpd[1031]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: === SNM TRANSITION === Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Previous ethernet state: disconnected Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: New ethernet state: connected Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Single Network Mode: enabled Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: First start: no Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: === END TRANSITION === Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: SNM: Ethernet connected, switching to ethernet (WiFi scan mode) Oct 15 17:21:04 volumio-acer sudo[1328]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd -k wlan0 Oct 15 17:21:04 volumio-acer sudo[1328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:04 volumio-acer dhcpcd[1330]: dhcpcd not running Oct 15 17:21:04 volumio-acer sudo[1328]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:04 volumio-acer wireless.js[891]: dhcpcd not running Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Oct 15 17:21:04 volumio-acer systemd[1]: hostapd.service: Scheduled restart job, restart counter is at 1. Oct 15 17:21:04 volumio-acer systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... Oct 15 17:21:04 volumio-acer dnsmasq[1243]: exiting on receipt of SIGTERM Oct 15 17:21:04 volumio-acer systemd[1]: dnsmasq.service: Deactivated successfully. Oct 15 17:21:04 volumio-acer systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. Oct 15 17:21:04 volumio-acer systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Oct 15 17:21:04 volumio-acer systemd[1]: Starting hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... Oct 15 17:21:04 volumio-acer systemd[1]: hostapd.service: Deactivated successfully. Oct 15 17:21:04 volumio-acer systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Oct 15 17:21:04 volumio-acer sudo[1340]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 15 17:21:04 volumio-acer sudo[1340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:04 volumio-acer sudo[1340]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:04 volumio-acer sudo[1343]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 15 17:21:04 volumio-acer sudo[1343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:04 volumio-acer systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Oct 15 17:21:04 volumio-acer sudo[1343]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:04 volumio-acer systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Oct 15 17:21:04 volumio-acer systemd[1]: welcome.service: Deactivated successfully. Oct 15 17:21:04 volumio-acer systemd[1]: Stopped welcome.service - Show a welcome message on console. Oct 15 17:21:04 volumio-acer systemd[1]: Stopping welcome.service - Show a welcome message on console... Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: Cleaning previous... Oct 15 17:21:04 volumio-acer systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 15 17:21:04 volumio-acer welcome[1345]: Resolved ip:[0] Oct 15 17:21:04 volumio-acer sudo[1347]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 15 17:21:04 volumio-acer sudo[1347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:04 volumio-acer sudo[1347]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: ensureInterfaceReady: ifconfig up failed: Error: Command failed: /usr/bin/sudo /sbin/ifconfig wlan0 up Oct 15 17:21:04 volumio-acer wireless.js[891]: SIOCSIFFLAGS: Operation not possible due to RF-kill Oct 15 17:21:04 volumio-acer systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 15 17:21:04 volumio-acer systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 1ms Oct 15 17:21:04 volumio-acer wireless.js[891]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 20:7c:8f:59:95:df) Oct 15 17:21:04 volumio-acer sudo[1359]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 15 17:21:04 volumio-acer sudo[1359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer sudo[1359]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer sudo[1367]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 15 17:21:05 volumio-acer sudo[1367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer sudo[1367]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer wireless.js[891]: command failed: Network is down (-100) Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "network"... Oct 15 17:21:05 volumio-acer volumio[1156]: info: Refreshing Cached IP Addresses Oct 15 17:21:05 volumio-acer sudo[1372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 17:21:05 volumio-acer sudo[1372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer sudo[1372]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer sudo[1375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 17:21:05 volumio-acer sudo[1375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "services"... Oct 15 17:21:05 volumio-acer sudo[1375]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "volumio5onboarding"... Oct 15 17:21:05 volumio-acer sudo[1386]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 15 17:21:05 volumio-acer sudo[1386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer sudo[1386]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "alsa_controller"... Oct 15 17:21:05 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "wizard"... Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "networkfs"... Oct 15 17:21:05 volumio-acer volumio[1156]: info: Starting Udev Watcher for removable devices Oct 15 17:21:05 volumio-acer sudo[1423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=daniel,password=198526,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=2.1 //192.168.31.66/sata2-4/share/music /mnt/NAS/sata2-4 Oct 15 17:21:05 volumio-acer sudo[1423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer sudo[1425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=daniel,password=198526,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=3.11 //192.168.31.66/Sata1-1/Music /mnt/NAS/Sata1-1 Oct 15 17:21:05 volumio-acer sudo[1425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:05 volumio-acer volumio[1156]: info: Ignoring mount for partition: boot Oct 15 17:21:05 volumio-acer volumio[1156]: info: Ignoring mount for partition: volumio Oct 15 17:21:05 volumio-acer volumio[1156]: info: Ignoring mount for partition: volumio_data Oct 15 17:21:05 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "volumio_command_line_client"... Oct 15 17:21:05 volumio-acer systemd[1]: systemd-rfkill.service: Deactivated successfully. Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "upnp"... Oct 15 17:21:05 volumio-acer volumio[1156]: info: [1792056065200] Starting Upmpd Daemon Oct 15 17:21:05 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "my_music"... Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "mpd"... Oct 15 17:21:05 volumio-acer kernel: netfs: FS-Cache loaded Oct 15 17:21:05 volumio-acer kernel: Key type dns_resolver registered Oct 15 17:21:05 volumio-acer sudo[1423]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer sudo[1425]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:05 volumio-acer kernel: Key type cifs.spnego registered Oct 15 17:21:05 volumio-acer kernel: Key type cifs.idmap registered Oct 15 17:21:05 volumio-acer kernel: CIFS: Attempting to mount //192.168.31.66/sata2-4/share/music Oct 15 17:21:05 volumio-acer kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Oct 15 17:21:05 volumio-acer kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Oct 15 17:21:05 volumio-acer kernel: CIFS: Attempting to mount //192.168.31.66/Sata1-1/Music Oct 15 17:21:05 volumio-acer kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Oct 15 17:21:05 volumio-acer kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Oct 15 17:21:05 volumio-acer volumio[1156]: info: Loading plugin "upnp_browser"... Oct 15 17:21:05 volumio-acer ntpd[1031]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:05 volumio-acer ntpd[1031]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 15 17:21:05 volumio-acer ntpd[1031]: DNS: dns_check: DNS error: -11, System error Oct 15 17:21:05 volumio-acer ntpd[1031]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Oct 15 17:21:06 volumio-acer volumio[1156]: info: Starting UPNP Browser Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "alarm-clock"... Oct 15 17:21:06 volumio-acer volumio-remote-updater[890]: [2026-10-15 17:21:06] [connect] Successful connection Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "airplay_emulation"... Oct 15 17:21:06 volumio-acer volumio[1156]: info: Starting Shairport Sync Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "last_100"... Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "webradio"... Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "i2s_dacs"... Oct 15 17:21:06 volumio-acer volumio[1156]: info: I2S DAC not set, start Auto-detection Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "volumiodiscovery"... Oct 15 17:21:06 volumio-acer volumio[1156]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 15 17:21:06 volumio-acer volumio[1156]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 15 17:21:06 volumio-acer volumio[1156]: *** WARNING *** For more information see Oct 15 17:21:06 volumio-acer volumio[1156]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 15 17:21:06 volumio-acer volumio[1156]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 15 17:21:06 volumio-acer volumio[1156]: *** WARNING *** For more information see Oct 15 17:21:06 volumio-acer node[1156]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 15 17:21:06 volumio-acer node[1156]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 15 17:21:06 volumio-acer node[1156]: *** WARNING *** For more information see Oct 15 17:21:06 volumio-acer node[1156]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 15 17:21:06 volumio-acer node[1156]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 15 17:21:06 volumio-acer node[1156]: *** WARNING *** For more information see Oct 15 17:21:06 volumio-acer volumio[1156]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 15 17:21:06 volumio-acer volumio[1156]: info: Discovery: Started advertising with name: Volumio-acer Oct 15 17:21:06 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 15 17:21:06 volumio-acer volumio[1156]: info: Loading plugin "now_playing"... Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading plugin "outputs"... Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading plugin "albumart"... Oct 15 17:21:07 volumio-acer volumio[1156]: info: Plugin example_plugin is not enabled Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading plugin "inputs"... Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading plugin "updater_comm"... Oct 15 17:21:07 volumio-acer volumio[1549]: Forking 3 albumart workers Oct 15 17:21:07 volumio-acer volumio[1156]: info: Plugin mpdemulation is not enabled Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading plugin "rest_api"... Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading plugin "websocket"... Oct 15 17:21:07 volumio-acer volumio[1156]: info: Starting Socket.io Server version 1.7.4 Oct 15 17:21:07 volumio-acer volumio[1156]: info: Loading i18n strings for locale zh Oct 15 17:21:07 volumio-acer volumio[1156]: Updating browse sources language Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 17:21:07 volumio-acer bash[1015]: setdatetime-helper: all HTTPS Date fallbacks failed Oct 15 17:21:07 volumio-acer systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 15 17:21:07 volumio-acer systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::initPlayerControls Oct 15 17:21:07 volumio-acer volumio[1560]: Starting albumart workers Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1565]: Starting albumart workers Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: Express server listening on port 3000 Oct 15 17:21:07 volumio-acer volumio[1561]: Starting albumart workers Oct 15 17:21:07 volumio-acer volumio[1156]: [Metrics] WebUI: 3s 965.20ms Oct 15 17:21:07 volumio-acer volumio[1156]: info: Setting Device type: x86 Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreStateMachine::resetVolumioState Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreStateMachine::getcurrentVolume Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioRetrievevolume Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 15 17:21:07 volumio-acer volumio[1156]: info: Completed loading Core Plugins Oct 15 17:21:07 volumio-acer volumio[1156]: info: Preparing to generate the ALSA configuration file Oct 15 17:21:07 volumio-acer volumio[1156]: info: Volumio Network Manager: Network status updated: 0 Oct 15 17:21:07 volumio-acer dbus-daemon[883]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.9' (uid=0 pid=1479 comm="/usr/lib/chromium/chromium --show-component-extens") Oct 15 17:21:07 volumio-acer volumio[1156]: info: Cannot mount NAS Sata1-1 at system boot, trial number 1 ,retrying in 5 seconds Oct 15 17:21:07 volumio-acer volumio[1156]: info: Cannot mount NAS sata2-4 at system boot, trial number 1 ,retrying in 5 seconds Oct 15 17:21:07 volumio-acer volumio[1156]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Oct 15 17:21:07 volumio-acer volumio[1156]: wlan0 Interface doesn't support scanning : Network is down Oct 15 17:21:07 volumio-acer volumio[1156]: info: Cannot use regular scanning, forcing with ap-force Oct 15 17:21:07 volumio-acer sudo[1601]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Oct 15 17:21:07 volumio-acer sudo[1601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:07 volumio-acer sudo[1601]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:07 volumio-acer volumio[1156]: command failed: Network is down (-100) Oct 15 17:21:07 volumio-acer volumio[1156]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Oct 15 17:21:07 volumio-acer volumio[1156]: command failed: Network is down (-100) Oct 15 17:21:07 volumio-acer volumio[1156]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Oct 15 17:21:07 volumio-acer systemd[1]: Starting bluetooth.service - Bluetooth service... Oct 15 17:21:07 volumio-acer volumio[1156]: info: VolumeController:: Volume=30 Mute =false Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:07 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreStateMachine::updateTrackBlock Oct 15 17:21:07 volumio-acer volumio[1156]: info: CorePlayQueue::getTrackBlock Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioRetrievevolume Oct 15 17:21:07 volumio-acer volumio-remote-updater[890]: [2026-10-15 17:21:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792056066 101 Oct 15 17:21:07 volumio-acer volumio[1156]: 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: 1 Oct 15 17:21:07 volumio-acer volumio[1156]: info: Reloading queue from file Oct 15 17:21:07 volumio-acer volumio[1156]: info: Asound.conf file unchanged, so no further update is needed Oct 15 17:21:07 volumio-acer volumio[1156]: info: Output device has changed, restarting MPD Oct 15 17:21:07 volumio-acer volumio[1156]: info: Output device has changed, restarting Shairport Sync Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:07 volumio-acer volumio[1156]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 17:21:07 volumio-acer volumio[1156]: info: ___________ START PLUGINS ___________ Oct 15 17:21:07 volumio-acer volumio[1156]: info: ControllerMpd::onStart: Initializing MPD Oct 15 17:21:07 volumio-acer volumio[1156]: info: Creating MPD Configuration file Oct 15 17:21:07 volumio-acer sudo[1627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 17:21:07 volumio-acer sudo[1627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:07 volumio-acer sudo[1625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 17:21:07 volumio-acer sudo[1650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 15 17:21:07 volumio-acer sudo[1650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:07 volumio-acer sudo[1625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:07 volumio-acer sudo[1625]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer sudo[1659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 15 17:21:08 volumio-acer sudo[1659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:08 volumio-acer sudo[1659]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 15 17:21:08 volumio-acer volumio[1156]: info: [1792056068026] CoreMusicLibrary::Adding element 媒体服务器 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 17:21:08 volumio-acer volumio[1156]: info: UPNP Browser: Client initialized successfully Oct 15 17:21:08 volumio-acer sudo[1670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 15 17:21:08 volumio-acer sudo[1670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:08 volumio-acer kernel: cryptd: max_cpu_qlen set to 1000 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:08 volumio-acer kernel: Bluetooth: Core ver 2.22 Oct 15 17:21:08 volumio-acer kernel: NET: Registered PF_BLUETOOTH protocol family Oct 15 17:21:08 volumio-acer kernel: Bluetooth: HCI device and connection manager initialized Oct 15 17:21:08 volumio-acer kernel: Bluetooth: HCI socket layer initialized Oct 15 17:21:08 volumio-acer kernel: Bluetooth: L2CAP socket layer initialized Oct 15 17:21:08 volumio-acer kernel: Bluetooth: SCO socket layer initialized Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Bluetooth daemon 5.83 Oct 15 17:21:08 volumio-acer systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 17:21:08 volumio-acer systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 17:21:08 volumio-acer systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 15 17:21:08 volumio-acer volumio[1156]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 17:21:08 volumio-acer sudo[1650]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:08 volumio-acer dbus-daemon[883]: [system] Successfully activated service 'org.bluez' Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Starting SDP server Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Excluding (cli) sap Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Excluding (cli) scanparam Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Excluding (cli) midi Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Excluding (cli) battery Oct 15 17:21:08 volumio-acer systemd[1]: Started bluetooth.service - Bluetooth service. Oct 15 17:21:08 volumio-acer systemd[1]: mpd.service: Deactivated successfully. Oct 15 17:21:08 volumio-acer systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 15 17:21:08 volumio-acer systemd[1]: mpd.socket: Deactivated successfully. Oct 15 17:21:08 volumio-acer systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 15 17:21:08 volumio-acer systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 15 17:21:08 volumio-acer systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 15 17:21:08 volumio-acer systemd[1]: Starting mpd.service - Music Player Daemon... Oct 15 17:21:08 volumio-acer volumio[1156]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 15 17:21:08 volumio-acer volumio[1156]: info: [1792056068127] CoreMusicLibrary::Adding element Last_100 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 15 17:21:08 volumio-acer volumio[1156]: info: [1792056068132] CoreMusicLibrary::Adding element Webradio Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 17:21:08 volumio-acer kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Oct 15 17:21:08 volumio-acer kernel: Bluetooth: BNEP filters: protocol multicast Oct 15 17:21:08 volumio-acer kernel: Bluetooth: BNEP socket layer initialized Oct 15 17:21:08 volumio-acer bluetoothd[1598]: Bluetooth management interface 1.23 initialized Oct 15 17:21:08 volumio-acer dbus-daemon[883]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.11' (uid=0 pid=1598 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 15 17:21:08 volumio-acer volumio[1156]: info: Initializing BBC Radios Oct 15 17:21:08 volumio-acer systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Oct 15 17:21:08 volumio-acer sudo[1712]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 15 17:21:08 volumio-acer sudo[1712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 15 17:21:08 volumio-acer sudo[1731]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 15 17:21:08 volumio-acer sudo[1712]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: [now-playing] ConfigUpdater: config is up to date. Oct 15 17:21:08 volumio-acer volumio[1156]: info: Volumio Calling Home Oct 15 17:21:08 volumio-acer dbus-daemon[883]: [system] Successfully activated service 'org.freedesktop.hostname1' Oct 15 17:21:08 volumio-acer systemd[1]: Started systemd-hostnamed.service - Hostname Service. Oct 15 17:21:08 volumio-acer volumio[1156]: info: [now-playing] App is listening on port 4004. Oct 15 17:21:08 volumio-acer volumio[1156]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreStateMachine::setRepeat false single undefined Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreStateMachine::setRandom null Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:08 volumio-acer volumio[1156]: info: VolumeController:: Volume=30 Mute =false Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:08 volumio-acer volumio[1156]: Unhandled rejection Error: No sockets available, cannot start. Oct 15 17:21:08 volumio-acer volumio[1156]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 15 17:21:08 volumio-acer volumio[1156]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 15 17:21:08 volumio-acer volumio[1156]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 15 17:21:08 volumio-acer volumio[1156]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 15 17:21:08 volumio-acer volumio[1156]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 15 17:21:08 volumio-acer volumio[1156]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 15 17:21:08 volumio-acer volumio[1156]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 15 17:21:08 volumio-acer volumio[1156]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 15 17:21:08 volumio-acer volumio[1156]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:156:14) Oct 15 17:21:08 volumio-acer volumio[1156]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 15 17:21:08 volumio-acer volumio[1156]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 15 17:21:08 volumio-acer volumio[1156]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 15 17:21:08 volumio-acer volumio[1156]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 15 17:21:08 volumio-acer volumio[1156]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 15 17:21:08 volumio-acer volumio[1156]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 15 17:21:08 volumio-acer volumio[1156]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 15 17:21:08 volumio-acer volumio[1156]: info: MPD Permissions set Oct 15 17:21:08 volumio-acer volumio[1156]: info: MPD Permissions set Oct 15 17:21:08 volumio-acer volumio[1156]: info: Discovery: adding 3c158be6-c021-43cf-8040-8c50261b10bf Oct 15 17:21:08 volumio-acer volumio[1156]: info: Discovery: Found device Volumio-acer Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer volumio[1156]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:08 volumio-acer volumio[1156]: info: Starting Shairport Sync Oct 15 17:21:08 volumio-acer volumio[1156]: info: Starting Shairport Sync Oct 15 17:21:08 volumio-acer volumio[1156]: info: Starting Shairport Sync Oct 15 17:21:08 volumio-acer sudo[1783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 17:21:08 volumio-acer sudo[1783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:08 volumio-acer sudo[1785]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 17:21:08 volumio-acer sudo[1785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.556+08:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer sudo[1781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 15 17:21:08 volumio-acer sudo[1781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:08 volumio-acer systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 15 17:21:08 volumio-acer systemd[1]: shairport-sync.service: Deactivated successfully. Oct 15 17:21:08 volumio-acer systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 17:21:08 volumio-acer systemd[1]: shairport-sync.service: Consumed 1.730s CPU time. Oct 15 17:21:08 volumio-acer volumio[1156]: 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 Oct 15 17:21:08 volumio-acer volumio[1156]: 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 Oct 15 17:21:08 volumio-acer avahi-daemon[882]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.31.148. Oct 15 17:21:08 volumio-acer dhcpcd[909]: eth0: using static address 192.168.31.148/24 Oct 15 17:21:08 volumio-acer dhcpcd[909]: eth0: adding route to 192.168.31.0/24 Oct 15 17:21:08 volumio-acer dhcpcd[909]: eth0: adding default route via 192.168.31.1 Oct 15 17:21:08 volumio-acer avahi-daemon[882]: New relevant interface eth0.IPv4 for mDNS. Oct 15 17:21:08 volumio-acer avahi-daemon[882]: Registering new address record for 192.168.31.148 on eth0.IPv4. Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.604+08:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.605+08:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.608+08:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Oct 15 17:21:08 volumio-acer systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.610+08:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.611+08:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.611+08:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Oct 15 17:21:08 volumio-acer volumio[1156]: info: Received Get System Info Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 17:21:08 volumio-acer volumio[1156]: info: Discovery: Getting this device information Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 17:21:08 volumio-acer sudo[1785]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.615+08:00 level=INFO msg="system info for bbe0b619cec338df70a9153d17047994" deviceName=Volumio-acer deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 15 17:21:08 volumio-acer sudo[1783]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer sudo[1781]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:08 volumio-acer volumio[1156]: info: Shairport-Sync Started Oct 15 17:21:08 volumio-acer volumio[1156]: Error adding Membership: Error: addMembership EINVAL Oct 15 17:21:08 volumio-acer volumio[1156]: info: Shairport-Sync Started Oct 15 17:21:08 volumio-acer volumio[1156]: info: Shairport-Sync Started Oct 15 17:21:08 volumio-acer systemd[1]: welcome.service: Deactivated successfully. Oct 15 17:21:08 volumio-acer systemd[1]: Stopped welcome.service - Show a welcome message on console. Oct 15 17:21:08 volumio-acer systemd[1]: Stopping welcome.service - Show a welcome message on console... Oct 15 17:21:08 volumio-acer systemd[1]: Starting welcome.service - Show a welcome message on console... Oct 15 17:21:08 volumio-acer welcome[1804]: Resolved ip:[1] 192.168.31.148 Oct 15 17:21:08 volumio-acer systemd[1]: Finished welcome.service - Show a welcome message on console. Oct 15 17:21:08 volumio-acer systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Oct 15 17:21:08 volumio-acer systemd[1]: Started nmbd.service - Samba NMB Daemon. Oct 15 17:21:08 volumio-acer nmbd[1085]: [2026/10/15 17:21:08.726525, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 15 17:21:08 volumio-acer nmbd[1085]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.31.148 for name WORKGROUP<1d>. Oct 15 17:21:08 volumio-acer nmbd[1085]: This response was from IP 192.168.31.80, reporting an IP address of 192.168.31.80. Oct 15 17:21:08 volumio-acer systemd[1]: Starting winbind.service - Samba Winbind Daemon... Oct 15 17:21:08 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:08.803+08:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 15 17:21:08 volumio-acer volumio[1156]: info: Received Get System Info Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 17:21:08 volumio-acer volumio[1156]: info: Discovery: Getting this device information Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:08 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:08 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 17:21:08 volumio-acer volumio-remote-updater[890]: Test mode disabled Oct 15 17:21:08 volumio-acer volumio-remote-updater[890]: Alpha mode disabled Oct 15 17:21:08 volumio-acer volumio-remote-updater[890]: Alpha legacy test mode disabled Oct 15 17:21:09 volumio-acer winbindd[1842]: [2026/10/15 17:21:09.018457, 0] ../../source3/winbindd/winbindd.c:1440(main) Oct 15 17:21:09 volumio-acer winbindd[1842]: winbindd version 4.17.12-Debian started. Oct 15 17:21:09 volumio-acer winbindd[1842]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 15 17:21:09 volumio-acer winbindd[1842]: [2026/10/15 17:21:09.032654, 0] ../../source3/winbindd/winbindd_cache.c:3117(initialize_winbindd_cache) Oct 15 17:21:09 volumio-acer winbindd[1842]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 15 17:21:09 volumio-acer systemd[1]: Started winbind.service - Samba Winbind Daemon. Oct 15 17:21:09 volumio-acer systemd[1]: Starting smbd.service - Samba SMB Daemon... Oct 15 17:21:09 volumio-acer smbd[1867]: [2026/10/15 17:21:09.326666, 0] ../../source3/smbd/server.c:1741(main) Oct 15 17:21:09 volumio-acer smbd[1867]: smbd version 4.17.12-Debian started. Oct 15 17:21:09 volumio-acer smbd[1867]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Oct 15 17:21:09 volumio-acer volumio[1156]: info: Discovery: this is already registered, 3c158be6-c021-43cf-8040-8c50261b10bf Oct 15 17:21:09 volumio-acer volumio[1156]: info: Discovery: Found device Volumio-acer Oct 15 17:21:09 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:09 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:09 volumio-acer ntpd[1031]: IO: Listen normally on 3 eth0 192.168.31.148:123 Oct 15 17:21:09 volumio-acer ntpd[1031]: IO: new interface(s) found: waking up resolver Oct 15 17:21:09 volumio-acer ntpd[1031]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:09 volumio-acer ntpd[1031]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 15 17:21:09 volumio-acer ntpd[1031]: DNS: Pool taking: 111.230.189.174 Oct 15 17:21:09 volumio-acer ntpd[1031]: DNS: Pool taking: 119.28.206.193 Oct 15 17:21:09 volumio-acer ntpd[1031]: DNS: Pool taking: 139.199.214.202 Oct 15 17:21:09 volumio-acer ntpd[1031]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Oct 15 17:21:09 volumio-acer systemd[1]: Started smbd.service - Samba SMB Daemon. Oct 15 17:21:09 volumio-acer systemd[1]: Reached target multi-user.target - Multi-User System. Oct 15 17:21:09 volumio-acer systemd[1]: Reached target graphical.target - Graphical Interface. Oct 15 17:21:09 volumio-acer systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Oct 15 17:21:09 volumio-acer systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Oct 15 17:21:09 volumio-acer systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Oct 15 17:21:10 volumio-acer volumio[1156]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 17:21:10 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:10.260+08: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" Oct 15 17:21:10 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:10.260+08: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" Oct 15 17:21:10 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:10.260+08: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" Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 17:21:10 volumio-acer volumio[1156]: info: Received Get System Info Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 17:21:10 volumio-acer volumio[1156]: info: Discovery: Getting this device information Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:10 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 15 17:21:10 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 15 17:21:10 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:10.278+08:00 level=INFO msg="enabling local network discovery" Oct 15 17:21:10 volumio-acer mpd[1737]: 2026-10-15T17:21:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 15 17:21:10 volumio-acer systemd[1]: Started mpd.service - Music Player Daemon. Oct 15 17:21:10 volumio-acer sudo[1627]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:10 volumio-acer systemd[1]: Startup finished in 27.317s (kernel) + 11.941s (userspace) = 39.258s. Oct 15 17:21:10 volumio-acer sudo[1670]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:10 volumio-acer volumio[1156]: info: Completed starting Core Plugins Oct 15 17:21:10 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:10 volumio-acer volumio[1156]: info: ----- MyVolumio plugins startup ---- Oct 15 17:21:10 volumio-acer volumio[1156]: info: ------------------------------------------- Oct 15 17:21:10 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 15 17:21:10 volumio-acer volumio[1156]: error: MPD error: The expression evaluated to a falsy value: Oct 15 17:21:10 volumio-acer volumio[1156]: assert.ok(self.idling) Oct 15 17:21:10 volumio-acer volumio[1156]: error: The expression evaluated to a falsy value: Oct 15 17:21:10 volumio-acer volumio[1156]: assert.ok(self.idling) Oct 15 17:21:10 volumio-acer volumio[1156]: info: MPD running with PID1737 Oct 15 17:21:10 volumio-acer volumio[1156]: ,establishing connection Oct 15 17:21:10 volumio-acer volumio[1156]: error: updateQueue error: null Oct 15 17:21:10 volumio-acer volumio[1156]: error: updateQueue error: null Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 162.159.200.123 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 210.28.130.4 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 5.79.108.34 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 139.199.215.251 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 2402:4e00:c050:2400:32d6:6914:76b4:1 Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 2a03:8600::ff Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: Pool taking: 2a03:8600::aa Oct 15 17:21:10 volumio-acer ntpd[1031]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Oct 15 17:21:10 volumio-acer volumio[1156]: 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: 4 Oct 15 17:21:11 volumio-acer volumio5-onboarding[1700]: time=2026-10-15T17:21:11.073+08:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 15 17:21:11 volumio-acer volumio[1156]: 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: 4 Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:11 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:11 volumio-acer ntpd[1031]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:11 volumio-acer ntpd[1031]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 15 17:21:11 volumio-acer ntpd[1031]: DNS: Pool taking: 95.111.202.5 Oct 15 17:21:11 volumio-acer ntpd[1031]: DNS: Pool taking: 162.159.200.1 Oct 15 17:21:11 volumio-acer ntpd[1031]: DNS: Pool taking: 193.182.111.142 Oct 15 17:21:11 volumio-acer ntpd[1031]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 15 17:21:11 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 15 17:21:11 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:11 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:11 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:11 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:12 volumio-acer ntpd[1031]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 15 17:21:12 volumio-acer ntpd[1031]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 15 17:21:12 volumio-acer ntpd[1031]: DNS: Pool taking: 84.16.67.12 Oct 15 17:21:12 volumio-acer ntpd[1031]: DNS: Pool skipping: 193.182.111.142 Oct 15 17:21:12 volumio-acer ntpd[1031]: DNS: Pool skipping: 111.230.189.174 Oct 15 17:21:12 volumio-acer ntpd[1031]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Oct 15 17:21:12 volumio-acer sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=daniel,password=198526,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=3.11 //192.168.31.66/Sata1-1/Music /mnt/NAS/Sata1-1 Oct 15 17:21:12 volumio-acer sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:12 volumio-acer sudo[1957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=daniel,password=198526,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=2.1 //192.168.31.66/sata2-4/share/music /mnt/NAS/sata2-4 Oct 15 17:21:12 volumio-acer sudo[1957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:12 volumio-acer kernel: CIFS: Attempting to mount //192.168.31.66/Sata1-1/Music Oct 15 17:21:12 volumio-acer sudo[1955]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:12 volumio-acer kernel: CIFS: Attempting to mount //192.168.31.66/sata2-4/share/music Oct 15 17:21:12 volumio-acer sudo[1957]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:13 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 15 17:21:13 volumio-acer volumio[1156]: info: Received Get System Info Oct 15 17:21:13 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 17:21:13 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 17:21:13 volumio-acer volumio[1156]: info: Discovery: Getting this device information Oct 15 17:21:13 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:13 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:13 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 17:21:15 volumio-acer volumio[1156]: info: Volumio Network Manager: Network status updated: 1 Oct 15 17:21:15 volumio-acer sudo[2013]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 17:21:15 volumio-acer sudo[2013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:15 volumio-acer sudo[2015]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 17:21:15 volumio-acer sudo[2015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:15 volumio-acer sudo[2013]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:15 volumio-acer sudo[2015]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:15 volumio-acer sudo[2018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 15 17:21:15 volumio-acer sudo[2018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:15 volumio-acer volumio[1156]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 15 17:21:16 volumio-acer systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Oct 15 17:21:16 volumio-acer systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 15 17:21:16 volumio-acer systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 15 17:21:16 volumio-acer sudo[2018]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:16 volumio-acer volumio[1156]: info: Upmpdcli Daemon Started Oct 15 17:21:17 volumio-acer ntpd[1031]: CLOCK: time stepped by 0.346941 Oct 15 17:21:17 volumio-acer ntpd[1031]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes Oct 15 17:21:18 volumio-acer volumio[1156]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.119&uuid=bbe0b619cec338df70a9153d17047994" http://updates.volumio.org/downloader-v1/track-device Oct 15 17:21:18 volumio-acer volumio[1156]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 15 17:21:18 volumio-acer volumio[1156]: Dload Upload Total Spent Left Speed Oct 15 17:21:18 volumio-acer volumio[1156]: [132B blob data] Oct 15 17:21:18 volumio-acer volumio[1156]: retrying in 5 seconds, trial 0 Oct 15 17:21:18 volumio-acer volumio[1156]: info: Volumio Calling Home Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin bluetooth to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin multiroom to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin metavolumio to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin cd_controller to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 15 17:21:20 volumio-acer upmpdcli[2047]: writing RSA key Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 15 17:21:20 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:20 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:20 volumio-acer volumio[1156]: info: Starting MyVolumio Remote Streaming Endpoints Oct 15 17:21:20 volumio-acer volumio[1156]: info: MyVolumio not started Oct 15 17:21:20 volumio-acer volumio[1156]: info: Initializing device activation check Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 15 17:21:20 volumio-acer volumio[1156]: info: Streaming services startup Oct 15 17:21:20 volumio-acer volumio[1156]: info: Starting Streaming Daemon Oct 15 17:21:20 volumio-acer sudo[2058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 15 17:21:20 volumio-acer sudo[2058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 17:21:20 volumio-acer volumio[1156]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 15 17:21:20 volumio-acer sudo[2058]: pam_unix(sudo:session): session closed for user root Oct 15 17:21:21 volumio-acer volumio[1156]: error: Cannot start Volumio Streaming Daemon Oct 15 17:21:21 volumio-acer volumio[1156]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 15 17:21:21 volumio-acer volumio[1156]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 15 17:21:21 volumio-acer volumio[1156]: info: Volumio called home Oct 15 17:21:22 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:22 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:29 volumio-acer systemd[1]: systemd-fsckd.service: Deactivated successfully. Oct 15 17:21:32 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:32 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:32 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:32 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:35 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 15 17:21:35 volumio-acer volumio[1156]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 15 17:21:35 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:35 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:38 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 15 17:21:38 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:38 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 15 17:21:38 volumio-acer systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 15 17:21:38 volumio-acer systemd[1]: systemd-hostnamed.service: Deactivated successfully. Oct 15 17:21:38 volumio-acer volumio-remote-updater[890]: Test mode disabled Oct 15 17:21:38 volumio-acer volumio-remote-updater[890]: Alpha mode disabled Oct 15 17:21:38 volumio-acer volumio-remote-updater[890]: Alpha legacy test mode disabled Oct 15 17:21:38 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 15 17:21:39 volumio-acer volumio[1156]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 15 17:21:39 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 15 17:21:39 volumio-acer systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 15 17:21:39 volumio-acer systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetBrowseSources Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 15 17:21:40 volumio-acer volumio[1156]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 15 17:21:40 volumio-acer volumio[1156]: info: Completed starting MyVolumio Plugin Oct 15 17:21:40 volumio-acer volumio[1156]: [Metrics] CommandRouter: 36s 601.69ms Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumiosetStartupVolume Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 15 17:21:40 volumio-acer volumio[1156]: info: VolumeController:: Setting startup Volume 30 Oct 15 17:21:40 volumio-acer volumio[1156]: info: VolumeController::SetAlsaVolume30 Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 17:21:40 volumio-acer volumio[1156]: info: CoreCommandRouter::Close All Modals sent Oct 15 17:21:41 volumio-acer volumio[1156]: info: CoreCommandRouter::Close All Modals sent Oct 15 17:21:41 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:41 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:41 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:42 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 15 17:21:42 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 17:21:42 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 15 17:21:42 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:42 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:44 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 17:21:44 volumio-acer volumio[1156]: info: Discovery: Getting this device information Oct 15 17:21:44 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:44 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:44 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 17:21:46 volumio-acer volumio[1156]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not access weather service: missing geographic coordinates. Oct 15 17:21:46 volumio-acer volumio[1156]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:95:19) Oct 15 17:21:46 volumio-acer volumio[1156]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:37) Oct 15 17:21:46 volumio-acer volumio[1156]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:47:13 Oct 15 17:21:46 volumio-acer volumio[1156]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Oct 15 17:21:46 volumio-acer volumio[1156]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:149:13) Oct 15 17:21:46 volumio-acer volumio[1156]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:119:3) Oct 15 17:21:46 volumio-acer volumio[1156]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Oct 15 17:21:46 volumio-acer volumio[1156]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Oct 15 17:21:46 volumio-acer volumio[1156]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Oct 15 17:21:46 volumio-acer volumio[1156]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Oct 15 17:21:46 volumio-acer volumio[1156]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Oct 15 17:21:46 volumio-acer volumio[1156]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Oct 15 17:21:46 volumio-acer volumio[1156]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Oct 15 17:21:46 volumio-acer volumio[1156]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Oct 15 17:21:46 volumio-acer volumio[1156]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Oct 15 17:21:46 volumio-acer volumio[1156]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Oct 15 17:21:46 volumio-acer volumio[1156]: verbose: New Socket.io Connection to 192.168.31.148:3000 from 192.168.31.8 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/140.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 15 17:21:46 volumio-acer volumio[1156]: error: [now-playing] No images found in My Backgrounds Oct 15 17:21:46 volumio-acer volumio[1156]: Thu, 15 Oct 2026 09:21:46 GMT express deprecated res.send(status): Use res.sendStatus(status) instead at data/plugins/user_interface/now_playing/dist/app/Handler.js:78:13 Oct 15 17:21:46 volumio-acer volumio[1156]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Oct 15 17:21:46 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Oct 15 17:21:46 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:46 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetQueue Oct 15 17:21:46 volumio-acer volumio[1156]: info: CoreStateMachine::getQueue Oct 15 17:21:46 volumio-acer volumio[1156]: info: CorePlayQueue::getQueue Oct 15 17:21:46 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 17:21:46 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 17:21:46 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:46 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:46 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/Jay/a521907d-879f-4dce-b9ae-14aa523f5da1.jpg' Oct 15 17:21:48 volumio-acer volumio[1156]: info: BOOT COMPLETED Oct 15 17:21:48 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioToggle Oct 15 17:21:48 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:48 volumio-acer volumio[1156]: info: CoreStateMachine::play index undefined Oct 15 17:21:48 volumio-acer volumio[1156]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 17:21:48 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:48 volumio-acer volumio[1156]: info: CoreStateMachine::startPlaybackTimer Oct 15 17:21:48 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:48 volumio-acer volumio[1156]: verbose: ControllerMpd::clearAddPlayTracks NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac Oct 15 17:21:48 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 17:21:48 volumio-acer volumio[1156]: info: sendMpdCommand stop took 2 milliseconds Oct 15 17:21:48 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 17:21:48 volumio-acer volumio[1156]: info: sendMpdCommand clear took 0 milliseconds Oct 15 17:21:48 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand add "NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac" Oct 15 17:21:48 volumio-acer volumio[1156]: info: Oct 15 17:21:48 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Oct 15 17:21:48 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:21:48 volumio-acer volumio[1156]: info: sendMpdCommand add "NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac" took 3 milliseconds Oct 15 17:21:48 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand play Oct 15 17:21:48 volumio-acer volumio[1156]: info: Oct 15 17:21:48 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Oct 15 17:21:48 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:21:48 volumio-acer volumio[1156]: info: ------------------------------ 6ms Oct 15 17:21:48 volumio-acer volumio[1156]: info: ------------------------------ 5ms Oct 15 17:21:48 volumio-acer volumio[1156]: info: sendMpdCommand play took 3 milliseconds Oct 15 17:21:48 volumio-acer volumio[1156]: info: ------------------------------ 2ms Oct 15 17:21:48 volumio-acer volumio[1156]: info: ------------------------------ 1ms Oct 15 17:21:48 volumio-acer volumio[1156]: info: Oct 15 17:21:48 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Oct 15 17:21:48 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:21:48 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:21:48 volumio-acer volumio[1156]: info: ------------------------------ 2ms Oct 15 17:21:48 volumio-acer volumio[1156]: info: ------------------------------ 1ms Oct 15 17:21:52 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:21:52 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:52 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:52 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:21:55 volumio-acer volumio[1156]: info: Oct 15 17:21:55 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:21:55 volumio-acer volumio[1156]: info: Oct 15 17:21:55 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:21:55 volumio-acer volumio[1156]: info: Oct 15 17:21:55 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:21:55 volumio-acer volumio[1156]: info: Oct 15 17:21:55 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand status took 3 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:21:55 volumio-acer volumio[1156]: info: Oct 15 17:21:55 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand status took 5 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand status took 5 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand status took 3 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand status took 2 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":209,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1 Kbps","isStreaming":false,"title":"伊斯坦堡","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","trackType":"flac"} Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: CURRENT POSITION 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus stop Oct 15 17:21:55 volumio-acer volumio[1156]: info: ------------------------------ 12ms Oct 15 17:21:55 volumio-acer volumio[1156]: info: Oct 15 17:21:55 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: info: sendMpdCommand status took 1 milliseconds Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":209,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"890 Kbps","isStreaming":false,"title":"伊斯坦堡","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","trackType":"flac"} Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: CURRENT POSITION 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:21:55 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":136,"duration":209,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"952 Kbps","isStreaming":false,"title":"伊斯坦堡","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","trackType":"flac"} Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: CURRENT POSITION 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:21:55 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":209,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"828 Kbps","isStreaming":false,"title":"伊斯坦堡","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","trackType":"flac"} Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: CURRENT POSITION 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:21:55 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":209,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"828 Kbps","isStreaming":false,"title":"伊斯坦堡","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","trackType":"flac"} Oct 15 17:21:55 volumio-acer volumio[1156]: verbose: CURRENT POSITION 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:21:55 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:55 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:55 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: ------------------------------ 43ms Oct 15 17:21:56 volumio-acer volumio[1156]: info: ------------------------------ 43ms Oct 15 17:21:56 volumio-acer volumio[1156]: info: ------------------------------ 43ms Oct 15 17:21:56 volumio-acer volumio[1156]: info: ------------------------------ 40ms Oct 15 17:21:56 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 32 milliseconds Oct 15 17:21:56 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:21:56 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:56 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":209,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"828 Kbps","isStreaming":false,"title":"伊斯坦堡","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","trackType":"flac"} Oct 15 17:21:56 volumio-acer volumio[1156]: verbose: CURRENT POSITION 0 Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:21:56 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:21:56 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:21:56 volumio-acer volumio[1156]: info: ------------------------------ 46ms Oct 15 17:22:02 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:22:02 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E8%8C%83%E7%89%B9%E8%A5%BF/7b52de4a-91b6-469c-b4dc-45478e72db9b.jpg' Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E5%8F%B6%E6%83%A0%E7%BE%8E/44764d51-6ca7-4158-8590-6352d959a923.jpg' Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E4%B8%83%E9%87%8C%E9%A6%99/92f33afb-f24f-4c80-bf63-52da6d08e6a2.jpg' Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E5%8D%81%E4%B8%80%E6%9C%88%E7%9A%84%E8%90%A7%E9%82%A6/a735a7ec-9436-49b4-9150-63cf04099e6d.jpg' Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E4%BE%9D%E7%84%B6%E8%8C%83%E7%89%B9%E8%A5%BF/8b72f300-7744-4b40-b1e3-b52a61ec2767.jpg' Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E6%88%91%E5%BE%88%E5%BF%99/ed7462a5-4f74-40ba-8cf3-958e25179a06.jpg' Oct 15 17:22:03 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E9%AD%94%E6%9D%B0%E5%BA%A7/3242c870-8edf-4db1-a149-6630eed44780.jpg' Oct 15 17:22:04 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E8%B7%A8%E6%97%B6%E4%BB%A3/60c63577-b35f-4472-bef3-3f1b9a1f0d58.jpg' Oct 15 17:22:04 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E6%83%8A%E5%8F%B9%E5%8F%B7/eb28ab52-e2d3-40dd-b14d-bd76e9cdbf35.jpg' Oct 15 17:22:04 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E5%8D%81%E4%BA%8C%E6%96%B0%E4%BD%9C/964f692f-c4ea-4b64-b87b-e30cbeb5b66c.jpg' Oct 15 17:22:04 volumio-acer volumio[1156]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%91%A8%E6%9D%B0%E4%BC%A6/%E5%91%A8%E6%9D%B0%E4%BC%A6%E7%9A%84%E5%BA%8A%E8%BE%B9%E6%95%85%E4%BA%8B/f2c0566d-39d3-4c2e-8fb4-de5dc0335e1b.jpg' Oct 15 17:22:11 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 17:22:11 volumio-acer volumio[1156]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"伊斯坦堡","artist":"周杰伦","album":"Jay","duration":"209","uri":"mnt/NAS/Sata1-1/周杰伦/Jay/周杰伦-伊斯坦堡.flac","service":""} Oct 15 17:22:11 volumio-acer volumio[1156]: info: [now-playing] LRCLIB getLyrics(): song: "伊斯坦堡" album: "Jay" artist: "周杰伦" duration: "209" Oct 15 17:22:11 volumio-acer volumio[1156]: info: [now-playing] LRCLIB getLyrics() API URL: https://lrclib.net/api/get?track_name=%E4%BC%8A%E6%96%AF%E5%9D%A6%E5%A0%A1&artist_name=%E5%91%A8%E6%9D%B0%E4%BC%A6&album_name=Jay&duration=209 Oct 15 17:22:12 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:22:12 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:22:12 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:22:12 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:22:22 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:22:22 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:22:32 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioGetState Oct 15 17:22:32 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:22:32 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:22:32 volumio-acer volumio[1156]: info: Listing playlists Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioNext Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::next Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::stPlaybackTimer Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::updateTrackBlock Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrackBlock Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::serviceStop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 0 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::serviceStop Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::stop Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand stop took 12 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::play index undefined Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::startPlaybackTimer Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::clearAddPlayTracks NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::updateTrackBlock Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrackBlock Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand stop took 1 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 1 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand clear took 1 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 1 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 2 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand add "NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac" Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: No code Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: No code Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 25ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 25ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:22:40 volumio-acer volumio[1156]: error: updateQueue error: null Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 28ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 27 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand add "NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac" took 27 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 4ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 3ms Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand play Oct 15 17:22:40 volumio-acer volumio[1156]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 32ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces system playlist update Oct 15 17:22:40 volumio-acer volumio[1156]: info: Ignoring MPD Status Update Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 11ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand play took 9 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 8ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 8ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 17:22:40 volumio-acer volumio[1156]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"印第安老斑鸠","artist":"周杰伦","album":"Jay","duration":"305","uri":"mnt/NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","service":""} Oct 15 17:22:40 volumio-acer volumio[1156]: info: [now-playing] LRCLIB getLyrics(): song: "印第安老斑鸠" album: "Jay" artist: "周杰伦" duration: "305" Oct 15 17:22:40 volumio-acer volumio[1156]: info: [now-playing] LRCLIB getLyrics() API URL: https://lrclib.net/api/get?track_name=%E5%8D%B0%E7%AC%AC%E5%AE%89%E8%80%81%E6%96%91%E9%B8%A0&artist_name=%E5%91%A8%E6%9D%B0%E4%BC%A6&album_name=Jay&duration=305 Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 2 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 3 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 3 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":305,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1 Kbps","isStreaming":false,"title":"印第安老斑鸠","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","trackType":"flac"} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus stop Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 6ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: Oct 15 17:22:40 volumio-acer volumio[1156]: ---------------------------- MPD announces state update: player Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::getState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand status Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 3 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 3 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand status took 1 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseState Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":305,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"558 Kbps","isStreaming":false,"title":"印第安老斑鸠","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","trackType":"flac"} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:22:40 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":305,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"880 Kbps","isStreaming":false,"title":"印第安老斑鸠","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","trackType":"flac"} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:22:40 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 24ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 23ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 17 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: info: sendMpdCommand playlistinfo took 17 milliseconds Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: ControllerMpd::parseTrackInfo Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":305,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"833 Kbps","isStreaming":false,"title":"印第安老斑鸠","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","trackType":"flac"} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:22:40 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":305,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"833 Kbps","isStreaming":false,"title":"印第安老斑鸠","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","trackType":"flac"} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:22:40 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ControllerMpd::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::servicePushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: STATE SERVICE {"status":"play","position":0,"seek":844,"duration":305,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"833 Kbps","isStreaming":false,"title":"印第安老斑鸠","artist":"周杰伦","album":"Jay","uri":"NAS/Sata1-1/周杰伦/Jay/周杰伦-印第安老斑鸠.flac","trackType":"flac"} Oct 15 17:22:40 volumio-acer volumio[1156]: verbose: CURRENT POSITION 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState stateService play Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::syncState currentStatus play Oct 15 17:22:40 volumio-acer volumio[1156]: info: Received an update from plugin. extracting info from payload Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreStateMachine::pushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: CorePlayQueue::getTrack 1 Oct 15 17:22:40 volumio-acer volumio[1156]: info: CoreCommandRouter::volumioPushState Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 43ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 42ms Oct 15 17:22:40 volumio-acer volumio[1156]: info: ------------------------------ 40ms Oct 15 17:22:41 volumio-acer volumio[1156]: error: [now-playing] Error fetching lyrics from LRCLIB (URL: https://lrclib.net/api/get?track_name=%E5%8D%B0%E7%AC%AC%E5%AE%89%E8%80%81%E6%96%91%E9%B8%A0&artist_name=%E5%91%A8%E6%9D%B0%E4%BC%A6&album_name=Jay&duration=305): Error: Response error: 429 - Too Many Requests Oct 15 17:22:41 volumio-acer volumio[1156]: at apiGet (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:21:15) Oct 15 17:22:41 volumio-acer volumio[1156]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Oct 15 17:22:41 volumio-acer volumio[1156]: at async LRCLibAPI.getLyrics (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:34:24) Oct 15 17:22:41 volumio-acer volumio[1156]: at async DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:62:37) Oct 15 17:22:41 volumio-acer volumio[1156]: at async /data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:131:40 Oct 15 17:22:41 volumio-acer volumio[1156]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 15 17:22:41 volumio-acer volumio[1156]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:176:15) Oct 15 17:22:41 volumio-acer volumio[1156]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Oct 15 17:22:41 volumio-acer volumio[1156]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Oct 15 17:22:41 volumio-acer volumio[1156]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 15 17:22:41 volumio-acer volumio[1156]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 17:22:41 volumio-acer volumio[1156]: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 15 17:22:41 volumio-acer volumio[1156]: at DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:68:19) Oct 15 17:22:41 volumio-acer volumio[1156]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Oct 15 17:22:41 volumio-acer volumio[1156]: at async /data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:131:40 Oct 15 17:22:41 volumio-acer volumio[1156]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 17:22:41 volumio-acer sudo[2471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-15 17:21' Oct 15 17:22:41 volumio-acer sudo[2471]: 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"