Jun 18 17:54:00 volumio-4 systemd[1]: boot.mount: Directory /boot to mount over is not empty, mounting anyway. Jun 18 17:54:00 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:00 volumio-4 systemd[1]: Mounting boot.mount - /boot... Jun 18 17:54:00 volumio-4 systemd[1]: dev-hugepages.mount - Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages). Jun 18 17:54:00 volumio-4 systemd[1]: Mounting var-spool-cups-tmp.mount - /var/spool/cups/tmp... Jun 18 17:54:00 volumio-4 systemd[1]: Mounted var-spool-cups-tmp.mount - /var/spool/cups/tmp. Jun 18 17:54:00 volumio-4 systemd[1]: Mounted boot.mount - /boot. Jun 18 17:54:00 volumio-4 systemd[1]: Reached target local-fs.target - Local File Systems. Jun 18 17:54:00 volumio-4 systemd[1]: Started ifup@eth0.service - ifup for eth0. Jun 18 17:54:00 volumio-4 systemd[1]: Started ifup@wlan0.service - ifup for wlan0. Jun 18 17:54:00 volumio-4 systemd[1]: Starting networking.service - Raise network interfaces... Jun 18 17:54:00 volumio-4 systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... Jun 18 17:54:00 volumio-4 systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... Jun 18 17:54:00 volumio-4 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). Jun 18 17:54:00 volumio-4 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Jun 18 17:54:00 volumio-4 systemd[1]: Received SIGRTMIN+20 from PID 294 (plymouthd). Jun 18 17:54:00 volumio-4 systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 780 (systemd-binfmt) Jun 18 17:54:00 volumio-4 systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... Jun 18 17:54:00 volumio-4 systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. Jun 18 17:54:00 volumio-4 systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. Jun 18 17:54:00 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:00 volumio-4 systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. Jun 18 17:54:00 volumio-4 kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Jun 18 17:54:00 volumio-4 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Jun 18 17:54:00 volumio-4 systemd[1]: Started haveged.service - Entropy Daemon based on the HAVEGE algorithm. Jun 18 17:54:00 volumio-4 systemd[1]: Starting rpcbind.service - RPC bind portmap service... Jun 18 17:54:00 volumio-4 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Jun 18 17:54:00 volumio-4 sh[811]: dhcpcd-9.4.1 starting Jun 18 17:54:00 volumio-4 dhcpcd[811]: dhcpcd-9.4.1 starting Jun 18 17:54:00 volumio-4 dhcpcd[827]: DUID 00:01:00:01:2f:df:e0:25:2c:cf:67:8d:b7:8e Jun 18 17:54:00 volumio-4 dhcpcd[827]: dhcp_vendor: No such process Jun 18 17:54:00 volumio-4 sh[811]: DUID 00:01:00:01:2f:df:e0:25:2c:cf:67:8d:b7:8e Jun 18 17:54:00 volumio-4 sh[811]: dhcp_vendor: No such process Jun 18 17:54:00 volumio-4 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Jun 18 17:54:00 volumio-4 systemd[1]: Reached target sysinit.target - System Initialization. Jun 18 17:54:00 volumio-4 systemd[1]: Started apt-daily.timer - Daily apt download activities. Jun 18 17:54:00 volumio-4 systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. Jun 18 17:54:00 volumio-4 systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. Jun 18 17:54:00 volumio-4 systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. Jun 18 17:54:00 volumio-4 systemd[1]: Started fstrim.timer - Discard unused blocks once a week. Jun 18 17:54:00 volumio-4 systemd[1]: Started man-db.timer - Daily man-db regeneration. Jun 18 17:54:00 volumio-4 systemd[1]: Started ntpsec-rotate-stats.timer - Rotate ntpd stats daily. Jun 18 17:54:00 volumio-4 systemd[1]: Started setdatetime-helper.timer - Volumio Time Sync Watchdog Timer. Jun 18 17:54:00 volumio-4 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Jun 18 17:54:00 volumio-4 systemd[1]: Reached target timers.target - Timer Units. Jun 18 17:54:00 volumio-4 systemd[1]: Listening on avahi-daemon.socket - Avahi mDNS/DNS-SD Stack Activation Socket. Jun 18 17:54:00 volumio-4 kernel: 8021q: 802.1Q VLAN Support v1.8 Jun 18 17:54:00 volumio-4 haveged[813]: haveged: command socket is listening at fd 3 Jun 18 17:54:00 volumio-4 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Jun 18 17:54:00 volumio-4 systemd[1]: Listening on lircd.socket. Jun 18 17:54:00 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:00 volumio-4 systemd[1]: Listening on triggerhappy.socket. Jun 18 17:54:00 volumio-4 systemd[1]: Reached target sockets.target - Socket Units. Jun 18 17:54:00 volumio-4 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). Jun 18 17:54:00 volumio-4 systemd[1]: Reached target basic.target - Basic System. Jun 18 17:54:00 volumio-4 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). Jun 18 17:54:00 volumio-4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 18 17:54:00 volumio-4 kernel: macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) Jun 18 17:54:00 volumio-4 kernel: macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode Jun 18 17:54:00 volumio-4 kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. Jun 18 17:54:00 volumio-4 systemd[1]: Starting alsa-restore.service - Save/Restore Sound Card State... Jun 18 17:54:00 volumio-4 dhcpcd[827]: eth0: waiting for carrier Jun 18 17:54:00 volumio-4 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jun 18 17:54:00 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:00 volumio-4 sh[811]: eth0: waiting for carrier Jun 18 17:54:00 volumio-4 alsactl[842]: No state is present for card vc4hdmi0 Jun 18 17:54:00 volumio-4 alsactl[842]: Found hardware: "vc4-hdmi" "" "" "" "" Jun 18 17:54:00 volumio-4 alsactl[842]: Hardware is initialized using a generic method Jun 18 17:54:00 volumio-4 alsactl[842]: No state is present for card vc4hdmi0 Jun 18 17:54:00 volumio-4 alsactl[842]: No state is present for card vc4hdmi1 Jun 18 17:54:00 volumio-4 alsactl[842]: Found hardware: "vc4-hdmi" "" "" "" "" Jun 18 17:54:00 volumio-4 alsactl[842]: Hardware is initialized using a generic method Jun 18 17:54:00 volumio-4 systemd[1]: Starting bluetooth.service - Bluetooth service... Jun 18 17:54:00 volumio-4 alsactl[842]: No state is present for card vc4hdmi1 Jun 18 17:54:00 volumio-4 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Jun 18 17:54:00 volumio-4 systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... Jun 18 17:54:00 volumio-4 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). Jun 18 17:54:00 volumio-4 systemd[1]: Starting glamor-test.service - Check for glamor... Jun 18 17:54:00 volumio-4 systemd[1]: headless_wireless.service - Copy user wpa_supplicant.conf was skipped because of an unmet condition check (ConditionPathExists=/boot/wpa_supplicant.conf). Jun 18 17:54:00 volumio-4 systemd[1]: Started iptables.service - Volumio Iptables Module. Jun 18 17:54:00 volumio-4 systemd[1]: Starting rp1-test.service - Check for RP1 displays for Xorg... Jun 18 17:54:00 volumio-4 systemd[1]: Starting rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates... Jun 18 17:54:00 volumio-4 systemd[1]: Starting systemd-logind.service - User Login Management... Jun 18 17:54:00 volumio-4 systemd[1]: Starting triggerhappy.service - triggerhappy global hotkey daemon... Jun 18 17:54:00 volumio-4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Unable to parse trigger line: Jun 18 17:54:00 volumio-4 thd[888]: Found socket passed from systemd Jun 18 17:54:00 volumio-4 systemd[1]: Started volumio-remote-updater.service - Volumio Remote OTA Updater. Jun 18 17:54:00 volumio-4 systemd[1]: Starting volumio_rfkill_unblock.service - Manage nl80211 modules blocking state... Jun 18 17:54:00 volumio-4 systemd[1]: volumiossh.service - Volumio SSH enabler was skipped because of an unmet condition check (ConditionPathExistsGlob=/boot/ssh{,.txt}). Jun 18 17:54:00 volumio-4 systemd[1]: Starting wireless.service - Wireless Services... Jun 18 17:54:00 volumio-4 systemd[1]: Started rpcbind.service - RPC bind portmap service. Jun 18 17:54:00 volumio-4 systemd[1]: Started triggerhappy.service - triggerhappy global hotkey daemon. Jun 18 17:54:00 volumio-4 systemd[1]: alsa-restore.service: Main process exited, code=exited, status=99/n/a Jun 18 17:54:00 volumio-4 systemd[1]: alsa-restore.service: Failed with result 'exit-code'. Jun 18 17:54:00 volumio-4 systemd[1]: Failed to start alsa-restore.service - Save/Restore Sound Card State. Jun 18 17:54:00 volumio-4 volumio_rfkill_unblock.sh[893]: Volumio WiFi Soft Blocked check script Jun 18 17:54:00 volumio-4 volumio_rfkill_unblock.sh[893]: Check if rfkill is available Jun 18 17:54:00 volumio-4 systemd[1]: e2scrub_reap.service: Deactivated successfully. Jun 18 17:54:00 volumio-4 systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. Jun 18 17:54:00 volumio-4 volumio_rfkill_unblock.sh[893]: Check if rfkill listed devices are already unblocked Jun 18 17:54:00 volumio-4 systemd[1]: Reached target rpcbind.target - RPC Port Mapper. Jun 18 17:54:00 volumio-4 systemd[1]: Reached target sound.target - Sound Card. Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Successfully dropped root privileges. Jun 18 17:54:00 volumio-4 avahi-daemon[875]: avahi-daemon 0.8 starting up. Jun 18 17:54:00 volumio-4 ifup[768]: ifup: waiting for lock on /run/network/ifstate.wlan0 Jun 18 17:54:00 volumio-4 sh[923]: wlan0=wlan0 Jun 18 17:54:00 volumio-4 systemd-logind[887]: New seat seat0. Jun 18 17:54:00 volumio-4 systemd-logind[887]: Watching system buttons on /dev/input/event0 (pwr_button) Jun 18 17:54:00 volumio-4 systemd-logind[887]: Watching system buttons on /dev/input/event1 (vc4-hdmi-0) Jun 18 17:54:00 volumio-4 systemd-logind[887]: Watching system buttons on /dev/input/event3 (vc4-hdmi-1) Jun 18 17:54:00 volumio-4 volumio_rfkill_unblock.sh[893]: Wi-Fi is already unblocked. Jun 18 17:54:00 volumio-4 rpi-eeprom-update[882]: WARNING: flashrom not found. Setting RPI_EEPROM_USE_FLASHROM to 0 Jun 18 17:54:00 volumio-4 systemd[1]: Finished volumio_rfkill_unblock.service - Manage nl80211 modules blocking state. Jun 18 17:54:00 volumio-4 systemd[1]: Finished networking.service - Raise network interfaces. Jun 18 17:54:00 volumio-4 systemd[1]: Starting dhcpcd.service - DHCP Client Daemon on all interfaces... Jun 18 17:54:00 volumio-4 bluetoothd[876]: Bluetooth daemon 5.72 Jun 18 17:54:00 volumio-4 dhcpcd[953]: dhcpcd-9.4.1 starting Jun 18 17:54:00 volumio-4 dhcpcd[961]: dev: loaded udev Jun 18 17:54:00 volumio-4 dhcpcd[961]: DUID 00:01:00:01:2f:df:e0:25:2c:cf:67:8d:b7:8e Jun 18 17:54:00 volumio-4 dhcpcd[961]: dhcp_vendor: No such process Jun 18 17:54:00 volumio-4 dhcpcd[953]: dhcp_vendor: No such process Jun 18 17:54:00 volumio-4 systemd[1]: Started dhcpcd.service - DHCP Client Daemon on all interfaces. Jun 18 17:54:00 volumio-4 dhcpcd[961]: eth0: waiting for carrier Jun 18 17:54:00 volumio-4 dhcpcd[961]: wlan0: waiting for carrier Jun 18 17:54:00 volumio-4 systemd[1]: Finished glamor-test.service - Check for glamor. Jun 18 17:54:00 volumio-4 systemd[1]: iptables.service: Deactivated successfully. Jun 18 17:54:00 volumio-4 systemd[1]: Started dbus.service - D-Bus System Message Bus. Jun 18 17:54:00 volumio-4 bluetoothd[876]: Starting SDP server Jun 18 17:54:00 volumio-4 bluetoothd[876]: Excluding (cli) wiimote Jun 18 17:54:00 volumio-4 bluetoothd[876]: Excluding (cli) sap Jun 18 17:54:00 volumio-4 bluetoothd[876]: Excluding (cli) midi Jun 18 17:54:00 volumio-4 bluetoothd[876]: Excluding (cli) battery Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Successfully called chroot(). Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Successfully dropped remaining capabilities. Jun 18 17:54:00 volumio-4 systemd[1]: Starting wpa_supplicant.service - WPA supplicant... Jun 18 17:54:00 volumio-4 dbus-daemon[877]: [system] Successfully activated service 'org.freedesktop.systemd1' Jun 18 17:54:00 volumio-4 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jun 18 17:54:00 volumio-4 systemd[1]: Started bluetooth.service - Bluetooth service. Jun 18 17:54:00 volumio-4 systemd[1]: Started systemd-logind.service - User Login Management. Jun 18 17:54:00 volumio-4 systemd[1]: Starting bluealsa.service - BlueALSA service... Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Loading service file /services/volumio.service. Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jun 18 17:54:00 volumio-4 avahi-daemon[875]: New relevant interface lo.IPv4 for mDNS. Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Network interface enumeration completed. Jun 18 17:54:00 volumio-4 avahi-daemon[875]: Registering new address record for 127.0.0.1 on lo.IPv4. Jun 18 17:54:00 volumio-4 systemd[1]: Finished rp1-test.service - Check for RP1 displays for Xorg. Jun 18 17:54:00 volumio-4 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jun 18 17:54:00 volumio-4 kernel: Bluetooth: BNEP filters: protocol multicast Jun 18 17:54:00 volumio-4 kernel: Bluetooth: BNEP socket layer initialized Jun 18 17:54:00 volumio-4 bluetoothd[876]: Bluetooth management interface 1.23 initialized Jun 18 17:54:00 volumio-4 dbus-daemon[877]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.1' (uid=0 pid=876 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Jun 18 17:54:00 volumio-4 kernel: Bluetooth: hci0: BCM: features 0x2f Jun 18 17:54:00 volumio-4 kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+-0190 Jun 18 17:54:00 volumio-4 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0382 Jun 18 17:54:00 volumio-4 kernel: Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac) Jun 18 17:54:00 volumio-4 systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Jun 18 17:54:00 volumio-4 bluetoothd[876]: Battery Provider Manager created Jun 18 17:54:00 volumio-4 kernel: Bluetooth: MGMT ver 1.23 Jun 18 17:54:00 volumio-4 kernel: NET: Registered PF_ALG protocol family Jun 18 17:54:00 volumio-4 dbus-daemon[877]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 18 17:54:00 volumio-4 systemd[1]: Started systemd-hostnamed.service - Hostname Service. Jun 18 17:54:00 volumio-4 haveged[813]: haveged: ver: 1.9.14; arch: generic; vend: ; build: (gcc 10.2.1 CTV); collect: 128K Jun 18 17:54:00 volumio-4 haveged[813]: haveged: cpu: (VC); data: 64K (V); inst: 64K (V); idx: 39/40; sz: 63356/63356 Jun 18 17:54:00 volumio-4 haveged[813]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99654 Jun 18 17:54:00 volumio-4 haveged[813]: haveged: fills: 0, generated: 0 Jun 18 17:54:00 volumio-4 systemd[1]: Started wpa_supplicant.service - WPA supplicant. Jun 18 17:54:00 volumio-4 wpa_supplicant[1017]: Successfully initialized wpa_supplicant Jun 18 17:54:00 volumio-4 systemd[1]: Reached target network.target - Network. Jun 18 17:54:00 volumio-4 systemd[1]: Reached target network-online.target - Network is Online. Jun 18 17:54:00 volumio-4 systemd[1]: Starting nmbd.service - Samba NMB Daemon... Jun 18 17:54:00 volumio-4 systemd[1]: Starting ntpsec.service - Network Time Service... Jun 18 17:54:00 volumio-4 systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... Jun 18 17:54:00 volumio-4 systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart... Jun 18 17:54:00 volumio-4 systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon... Jun 18 17:54:00 volumio-4 sm-notify[1036]: Version 2.6.2 starting Jun 18 17:54:00 volumio-4 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jun 18 17:54:00 volumio-4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 18 17:54:00 volumio-4 bluetoothd[876]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled Jun 18 17:54:00 volumio-4 bluetoothd[876]: bap: Operation not supported (95) Jun 18 17:54:00 volumio-4 bluetoothd[876]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16 Jun 18 17:54:00 volumio-4 systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Jun 18 17:54:00 volumio-4 dbus-daemon[877]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.6' (uid=0 pid=1044 comm="timedatectl show --property=NTPSynchronized --valu") Jun 18 17:54:00 volumio-4 systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor. Jun 18 17:54:00 volumio-4 systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 18 17:54:00 volumio-4 systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. Jun 18 17:54:00 volumio-4 systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart. Jun 18 17:54:00 volumio-4 systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 18 17:54:00 volumio-4 rpi-eeprom-update[882]: BOOTLOADER: up to date Jun 18 17:54:00 volumio-4 rpi-eeprom-update[882]: CURRENT: Thu May 8 14:13:17 UTC 2025 (1746713597) Jun 18 17:54:00 volumio-4 rpi-eeprom-update[882]: LATEST: Thu May 8 14:13:17 UTC 2025 (1746713597) Jun 18 17:54:00 volumio-4 rpi-eeprom-update[882]: RELEASE: default (/usr/lib/firmware/raspberrypi/bootloader-2712/default) Jun 18 17:54:00 volumio-4 rpi-eeprom-update[882]: Use raspi-config to change the release. Jun 18 17:54:00 volumio-4 systemd[1]: Finished rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates. Jun 18 17:54:00 volumio-4 ntpd[1050]: INIT: ntpd ntpsec-1.2.2: Starting Jun 18 17:54:00 volumio-4 ntpd[1050]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Jun 18 17:54:00 volumio-4 ntp-systemd-wrapper[1050]: 2025-06-18T17:54:00 ntpd[1050]: INIT: ntpd ntpsec-1.2.2: Starting Jun 18 17:54:00 volumio-4 ntp-systemd-wrapper[1050]: 2025-06-18T17:54:00 ntpd[1050]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Jun 18 17:54:00 volumio-4 systemd[1]: Started ntpsec.service - Network Time Service. Jun 18 17:54:00 volumio-4 welcome[1058]: Resolved ip:[0] Jun 18 17:54:00 volumio-4 volumio-remote-updater[892]: Volumio OTA Client: 1.7.0 Jun 18 17:54:00 volumio-4 volumio-remote-updater[892]: Error: No active session Jun 18 17:54:00 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:00] [info] asio async_connect error: asio.system:111 (Connection refused) Jun 18 17:54:00 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:00] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jun 18 17:54:00 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:00] [error] handle_connect error: Connection refused Jun 18 17:54:00 volumio-4 dbus-daemon[877]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 18 17:54:00 volumio-4 systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 18 17:54:00 volumio-4 bash[1041]: Time is not synchronized. Attempting to sync... Jun 18 17:54:00 volumio-4 upmpdcli[889]: Could not open config: /tmp/upmpdcli.conf Jun 18 17:54:00 volumio-4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jun 18 17:54:00 volumio-4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jun 18 17:54:00 volumio-4 ntpd[1064]: INIT: precision = 0.407 usec (-21) Jun 18 17:54:00 volumio-4 ntpd[1064]: INIT: successfully locked into RAM Jun 18 17:54:00 volumio-4 systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 18 17:54:00 volumio-4 ntpd[1064]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf Jun 18 17:54:00 volumio-4 ntpd[1064]: CONFIG: restrict nopeer ignored Jun 18 17:54:01 volumio-4 ntpd[1064]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 18 17:54:01 volumio-4 ntpd[1064]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2025-12-28T00:00Z last=2017-01-01T00:00Z ofs=37 Jun 18 17:54:01 volumio-4 ntpd[1064]: INIT: Using SO_TIMESTAMPNS(ns) Jun 18 17:54:01 volumio-4 ntpd[1064]: IO: Listen and drop on 0 v6wildcard [::]:123 Jun 18 17:54:01 volumio-4 ntpd[1064]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 18 17:54:01 volumio-4 ntpd[1064]: IO: Listen normally on 2 lo 127.0.0.1:123 Jun 18 17:54:01 volumio-4 ntpd[1064]: IO: Listening on routing socket on fd #19 for interface updates Jun 18 17:54:01 volumio-4 bash[1041]: Sync attempt failed. Jun 18 17:54:01 volumio-4 ntpd[1064]: INIT: This system has a 32-bit time_t. Jun 18 17:54:01 volumio-4 ntpd[1064]: INIT: This ntpd will fail on 2038-01-19T03:14:07Z. Jun 18 17:54:01 volumio-4 ntpd[1064]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jun 18 17:54:01 volumio-4 ntpd[1064]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090 Jun 18 17:54:01 volumio-4 ntpd[1064]: INIT: Running with OpenSSL 3.0.16 11 Feb 2025, 30000100 Jun 18 17:54:01 volumio-4 ntpd[1064]: NTSc: Using system default root certificates. Jun 18 17:54:01 volumio-4 systemd[1]: Mounting run-rpc_pipefs.mount - RPC Pipe File System... Jun 18 17:54:01 volumio-4 systemd[1]: setdatetime-helper.service: Deactivated successfully. Jun 18 17:54:01 volumio-4 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jun 18 17:54:01 volumio-4 systemd[1]: Mounted run-rpc_pipefs.mount - RPC Pipe File System. Jun 18 17:54:01 volumio-4 systemd[1]: Reached target rpc_pipefs.target. Jun 18 17:54:01 volumio-4 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). Jun 18 17:54:01 volumio-4 systemd[1]: Reached target nfs-client.target - NFS client services. Jun 18 17:54:01 volumio-4 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Jun 18 17:54:01 volumio-4 systemd[1]: Reached target remote-fs.target - Remote File Systems. Jun 18 17:54:01 volumio-4 systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically... Jun 18 17:54:01 volumio-4 systemd[1]: Starting loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling... Jun 18 17:54:01 volumio-4 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). Jun 18 17:54:01 volumio-4 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Jun 18 17:54:01 volumio-4 sshd[1080]: Server listening on 0.0.0.0 port 22. Jun 18 17:54:01 volumio-4 systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Jun 18 17:54:01 volumio-4 sshd[1080]: Server listening on :: port 22. Jun 18 17:54:01 volumio-4 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Jun 18 17:54:01 volumio-4 systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... Jun 18 17:54:01 volumio-4 ntpd[1064]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory Jun 18 17:54:01 volumio-4 ifplugd(eth0)[1109]: ifplugd 0.28 initializing. Jun 18 17:54:01 volumio-4 ifplugd(eth0)[1109]: Using interface eth0/2C:CF:67:8D:B7:8D with driver (version: 6.12.27-v8+) Jun 18 17:54:01 volumio-4 ifplugd(eth0)[1109]: Using detection mode: SIOCETHTOOL Jun 18 17:54:01 volumio-4 ifplugd(eth0)[1109]: Initialization complete, link beat not detected. Jun 18 17:54:01 volumio-4 bluealsa[1018]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa Jun 18 17:54:01 volumio-4 bluealsa[1018]: main.c:663: Starting main dispatching loop Jun 18 17:54:01 volumio-4 bluealsa[1018]: main.c:118: Acquired D-Bus service name: org.bluealsa Jun 18 17:54:01 volumio-4 bluealsa[1018]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa Jun 18 17:54:01 volumio-4 systemd[1]: Started bluealsa.service - BlueALSA service. Jun 18 17:54:01 volumio-4 systemd[1]: Reached target bluetooth.target - Bluetooth Support. Jun 18 17:54:01 volumio-4 bluealsa[1018]: bluez.c:153: Registering media application: /org/bluez/hci0 Jun 18 17:54:01 volumio-4 bluealsa[1018]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1 Jun 18 17:54:01 volumio-4 bluealsa[1018]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2 Jun 18 17:54:01 volumio-4 bluealsa[1018]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1 Jun 18 17:54:01 volumio-4 bluealsa[1018]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2 Jun 18 17:54:01 volumio-4 dbus-daemon[877]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service' requested by ':1.8' (uid=0 pid=1018 comm="/usr/bin/bluealsa -S -p a2dp-source -p a2dp-sink") Jun 18 17:54:01 volumio-4 loadcpufreq[1082]: Loading cpufreq kernel modules...done (none). Jun 18 17:54:01 volumio-4 systemd[1]: Starting upower.service - Daemon for power management... Jun 18 17:54:01 volumio-4 systemd[1]: Started loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling. Jun 18 17:54:01 volumio-4 systemd[1]: Starting cpufrequtils.service - LSB: set CPUFreq kernel parameters... Jun 18 17:54:01 volumio-4 avahi-daemon[875]: Server startup complete. Host name is volumio-4.local. Local service cookie is 2006475458. Jun 18 17:54:01 volumio-4 ifplugd[1081]: Network Interface Plugging Daemon...start eth0...done. Jun 18 17:54:01 volumio-4 systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Jun 18 17:54:01 volumio-4 dbus-daemon[877]: [system] Successfully activated service 'org.freedesktop.UPower' Jun 18 17:54:01 volumio-4 systemd[1]: Started upower.service - Daemon for power management. Jun 18 17:54:01 volumio-4 cpufrequtils[1138]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jun 18 17:54:01 volumio-4 systemd[1]: Started cpufrequtils.service - LSB: set CPUFreq kernel parameters. Jun 18 17:54:01 volumio-4 bluetoothd[876]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/source/1 Jun 18 17:54:01 volumio-4 bluetoothd[876]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/sink/2 Jun 18 17:54:01 volumio-4 bluetoothd[876]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/source/2 Jun 18 17:54:01 volumio-4 bluetoothd[876]: Endpoint registered: sender=:1.8 path=/org/bluez/hci0/A2DP/SBC/sink/1 Jun 18 17:54:01 volumio-4 systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Jun 18 17:54:01 volumio-4 systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Jun 18 17:54:01 volumio-4 sudo[1181]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Jun 18 17:54:01 volumio-4 sudo[1181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:01 volumio-4 sudo[1181]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:01 volumio-4 sudo[1183]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Jun 18 17:54:01 volumio-4 sudo[1183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:01 volumio-4 nmbd[1179]: [2025/06/18 17:54:01.634125, 0] ../../source3/nmbd/nmbd.c:901(main) Jun 18 17:54:01 volumio-4 nmbd[1179]: nmbd version 4.17.8-Raspbian started. Jun 18 17:54:01 volumio-4 nmbd[1179]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jun 18 17:54:01 volumio-4 nmbd[1179]: [2025/06/18 17:54:01.635427, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Jun 18 17:54:01 volumio-4 nmbd[1179]: started asyncdns process 1185 Jun 18 17:54:02 volumio-4 avahi-daemon[875]: Service "Volumio 4" (/services/volumio.service) successfully established. Jun 18 17:54:02 volumio-4 ntpd[1064]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:02 volumio-4 ntpd[1064]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jun 18 17:54:02 volumio-4 ntpd[1064]: DNS: dns_check: DNS error: -11, System error Jun 18 17:54:02 volumio-4 ntpd[1064]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Jun 18 17:54:02 volumio-4 nmbd[1179]: [2025/06/18 17:54:02.135515, 0] ../../lib/util/become_daemon.c:150(daemon_status) Jun 18 17:54:02 volumio-4 nmbd[1179]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jun 18 17:54:02 volumio-4 nmbd[1179]: [2025/06/18 17:54:02.135556, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Jun 18 17:54:02 volumio-4 nmbd[1179]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jun 18 17:54:02 volumio-4 sudo[1183]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:02 volumio-4 sudo[1193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 18 17:54:02 volumio-4 sudo[1193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:02 volumio-4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 18 17:54:02 volumio-4 sudo[1193]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:02 volumio-4 sudo[1195]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jun 18 17:54:02 volumio-4 sudo[1195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:02 volumio-4 sudo[1195]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:02 volumio-4 sudo[1203]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 18 17:54:02 volumio-4 sudo[1203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:02 volumio-4 sudo[1203]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:02 volumio-4 sudo[1205]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jun 18 17:54:02 volumio-4 sudo[1205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:03 volumio-4 ntpd[1064]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:03 volumio-4 ntpd[1064]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jun 18 17:54:03 volumio-4 ntpd[1064]: DNS: dns_check: DNS error: -11, System error Jun 18 17:54:03 volumio-4 ntpd[1064]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Jun 18 17:54:04 volumio-4 ntpd[1064]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:04 volumio-4 ntpd[1064]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jun 18 17:54:04 volumio-4 ntpd[1064]: DNS: dns_check: DNS error: -11, System error Jun 18 17:54:04 volumio-4 ntpd[1064]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Jun 18 17:54:04 volumio-4 systemd[1]: systemd-rfkill.service: Deactivated successfully. Jun 18 17:54:05 volumio-4 sudo[1205]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:05 volumio-4 sudo[1213]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 18 17:54:05 volumio-4 sudo[1213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:05 volumio-4 sudo[1213]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:05 volumio-4 sudo[1215]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set MT Jun 18 17:54:05 volumio-4 sudo[1215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:05 volumio-4 sudo[1215]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:05 volumio-4 sudo[1223]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Jun 18 17:54:05 volumio-4 sudo[1223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:05 volumio-4 sudo[1223]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:05 volumio-4 sudo[1225]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Jun 18 17:54:05 volumio-4 sudo[1225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:05 volumio-4 ntpd[1064]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:05 volumio-4 ntpd[1064]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jun 18 17:54:05 volumio-4 ntpd[1064]: DNS: dns_check: DNS error: -11, System error Jun 18 17:54:05 volumio-4 ntpd[1064]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Jun 18 17:54:05 volumio-4 sudo[1225]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:05 volumio-4 wpa_supplicant[1231]: Successfully initialized wpa_supplicant Jun 18 17:54:05 volumio-4 sudo[1232]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jun 18 17:54:05 volumio-4 sudo[1232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:05 volumio-4 dhcpcd[961]: control command: /sbin/dhcpcd Jun 18 17:54:05 volumio-4 dhcpcd[961]: control_free: No such file or directory Jun 18 17:54:05 volumio-4 sudo[1232]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:05 volumio-4 dhcpcd[961]: lo: IAID 00:00:00:00 Jun 18 17:54:05 volumio-4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 18 17:54:05 volumio-4 dhcpcd[961]: lo: ipv6_start: Operation not supported Jun 18 17:54:05 volumio-4 dhcpcd[961]: lo: using static address 127.0.0.1/8 Jun 18 17:54:05 volumio-4 dhcpcd[961]: lo: adding route to 127.0.0.0/8 Jun 18 17:54:05 volumio-4 systemd[1]: Reached target ip-changed@lo.target - IP Address changed on lo. Jun 18 17:54:05 volumio-4 wpa_supplicant[1231]: nl80211: kernel reports: Registration to specific type not supported Jun 18 17:54:05 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:05] [info] asio async_connect error: asio.system:111 (Connection refused) Jun 18 17:54:05 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:05] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jun 18 17:54:05 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:05] [error] handle_connect error: Connection refused Jun 18 17:54:06 volumio-4 sudo[1258]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:06 volumio-4 sudo[1258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:06 volumio-4 sudo[1258]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:07 volumio-4 sudo[1262]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:07 volumio-4 sudo[1262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:07 volumio-4 sudo[1262]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:08 volumio-4 wpa_supplicant[1255]: wlan0: Trying to associate with 64:d1:54:17:57:19 (SSID='MikroTik' freq=2437 MHz) Jun 18 17:54:08 volumio-4 wpa_supplicant[1255]: wlan0: Associated with 64:d1:54:17:57:19 Jun 18 17:54:08 volumio-4 wpa_supplicant[1255]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 18 17:54:08 volumio-4 wpa_supplicant[1255]: wlan0: WPA: Key negotiation completed with 64:d1:54:17:57:19 [PTK=CCMP GTK=CCMP] Jun 18 17:54:08 volumio-4 wpa_supplicant[1255]: wlan0: CTRL-EVENT-CONNECTED - Connection to 64:d1:54:17:57:19 completed [id=0 id_str=] Jun 18 17:54:08 volumio-4 dhcpcd[961]: wlan0: carrier acquired Jun 18 17:54:08 volumio-4 dhcpcd[961]: wlan0: connected to Access Point: MikroTik Jun 18 17:54:08 volumio-4 dhcpcd[961]: wlan0: IAID 67:8d:b7:8e Jun 18 17:54:08 volumio-4 dhcpcd[961]: wlan0: adding address fe80::2ecf:67ff:fe8d:b78e Jun 18 17:54:08 volumio-4 dhcpcd[961]: ipv6_addaddr1: Permission denied Jun 18 17:54:08 volumio-4 dhcpcd[961]: wlan0: probing address 192.168.88.191/24 Jun 18 17:54:08 volumio-4 dhcpcd[961]: wlan0: soliciting an IPv6 router Jun 18 17:54:08 volumio-4 sudo[1268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:08 volumio-4 sudo[1268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:08 volumio-4 sudo[1268]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:09 volumio-4 sudo[1272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:09 volumio-4 sudo[1272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:09 volumio-4 sudo[1272]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:10 volumio-4 sudo[1276]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:10 volumio-4 sudo[1276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:10 volumio-4 sudo[1276]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:11 volumio-4 sudo[1280]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:11 volumio-4 sudo[1280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:11 volumio-4 sudo[1280]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:12 volumio-4 sudo[1284]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:12 volumio-4 sudo[1284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:12 volumio-4 sudo[1284]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:12 volumio-4 dhcpcd[961]: wlan0: using static address 192.168.88.191/24 Jun 18 17:54:12 volumio-4 avahi-daemon[875]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.88.191. Jun 18 17:54:12 volumio-4 avahi-daemon[875]: New relevant interface wlan0.IPv4 for mDNS. Jun 18 17:54:12 volumio-4 avahi-daemon[875]: Registering new address record for 192.168.88.191 on wlan0.IPv4. Jun 18 17:54:12 volumio-4 dhcpcd[961]: wlan0: router 192.168.1.1 requires a host route Jun 18 17:54:12 volumio-4 dhcpcd[961]: wlan0: adding route to 192.168.88.0/24 Jun 18 17:54:12 volumio-4 dhcpcd[961]: wlan0: adding host route to 192.168.1.1 Jun 18 17:54:12 volumio-4 dhcpcd[961]: wlan0: adding default route via 192.168.1.1 Jun 18 17:54:12 volumio-4 systemd[1]: welcome.service: Deactivated successfully. Jun 18 17:54:12 volumio-4 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jun 18 17:54:12 volumio-4 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jun 18 17:54:12 volumio-4 systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 18 17:54:12 volumio-4 welcome[1305]: Resolved ip:[1] 192.168.88.191 Jun 18 17:54:12 volumio-4 systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 18 17:54:12 volumio-4 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Jun 18 17:54:13 volumio-4 systemd[1]: Started nmbd.service - Samba NMB Daemon. Jun 18 17:54:13 volumio-4 nmbd[1179]: [2025/06/18 17:54:13.109615, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jun 18 17:54:13 volumio-4 nmbd[1179]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.88.191 for name WORKGROUP<1d>. Jun 18 17:54:13 volumio-4 nmbd[1179]: This response was from IP 192.168.88.30, reporting an IP address of 192.168.88.30. Jun 18 17:54:13 volumio-4 systemd[1]: Starting winbind.service - Samba Winbind Daemon... Jun 18 17:54:13 volumio-4 winbindd[1313]: [2025/06/18 17:54:13.236489, 0] ../../source3/winbindd/winbindd.c:1440(main) Jun 18 17:54:13 volumio-4 winbindd[1313]: winbindd version 4.17.8-Raspbian started. Jun 18 17:54:13 volumio-4 winbindd[1313]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jun 18 17:54:13 volumio-4 winbindd[1313]: [2025/06/18 17:54:13.240902, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Jun 18 17:54:13 volumio-4 winbindd[1313]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 18 17:54:13 volumio-4 systemd[1]: Started winbind.service - Samba Winbind Daemon. Jun 18 17:54:13 volumio-4 systemd[1]: Starting smbd.service - Samba SMB Daemon... Jun 18 17:54:13 volumio-4 smbd[1330]: [2025/06/18 17:54:13.390249, 0] ../../source3/smbd/server.c:1741(main) Jun 18 17:54:13 volumio-4 smbd[1330]: smbd version 4.17.8-Raspbian started. Jun 18 17:54:13 volumio-4 smbd[1330]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jun 18 17:54:13 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:13] [info] asio async_connect error: asio.system:111 (Connection refused) Jun 18 17:54:13 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:13] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jun 18 17:54:13 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:13] [error] handle_connect error: Connection refused Jun 18 17:54:13 volumio-4 systemd[1]: Started smbd.service - Samba SMB Daemon. Jun 18 17:54:13 volumio-4 sudo[1341]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jun 18 17:54:13 volumio-4 sudo[1341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:13 volumio-4 sudo[1341]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:13 volumio-4 sudo[1344]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 18 17:54:13 volumio-4 sudo[1344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:13 volumio-4 sudo[1344]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:13 volumio-4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 18 17:54:13 volumio-4 systemd[1]: shairport-sync.service: Deactivated successfully. Jun 18 17:54:13 volumio-4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 18 17:54:13 volumio-4 systemd[1]: shairport-sync.service: Consumed 1.600s CPU time. Jun 18 17:54:13 volumio-4 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jun 18 17:54:13 volumio-4 avahi-daemon[875]: Got SIGTERM, quitting. Jun 18 17:54:13 volumio-4 avahi-daemon[875]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.88.191. Jun 18 17:54:13 volumio-4 avahi-daemon[875]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jun 18 17:54:13 volumio-4 avahi-daemon[875]: avahi-daemon 0.8 exiting. Jun 18 17:54:13 volumio-4 systemd[1]: avahi-daemon.service: Deactivated successfully. Jun 18 17:54:13 volumio-4 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jun 18 17:54:13 volumio-4 dbus-daemon[877]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.13' (uid=0 pid=1330 comm="/usr/sbin/smbd --foreground --no-process-group") Jun 18 17:54:13 volumio-4 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Process 875 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Successfully dropped root privileges. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: avahi-daemon 0.8 starting up. Jun 18 17:54:13 volumio-4 dbus-daemon[877]: [system] Successfully activated service 'org.freedesktop.Avahi' Jun 18 17:54:13 volumio-4 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Successfully called chroot(). Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Successfully dropped remaining capabilities. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Loading service file /services/volumio.service. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.88.191. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: New relevant interface wlan0.IPv4 for mDNS. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: New relevant interface lo.IPv4 for mDNS. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Network interface enumeration completed. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Registering new address record for 192.168.88.191 on wlan0.IPv4. Jun 18 17:54:13 volumio-4 avahi-daemon[1349]: Registering new address record for 127.0.0.1 on lo.IPv4. Jun 18 17:54:13 volumio-4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 18 17:54:13 volumio-4 systemd[1]: Started wireless.service - Wireless Services. Jun 18 17:54:13 volumio-4 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 18 17:54:13 volumio-4 systemd[1]: Started volumio.service - Volumio Backend Module. Jun 18 17:54:13 volumio-4 systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Jun 18 17:54:13 volumio-4 systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Jun 18 17:54:13 volumio-4 systemd[1]: Received SIGRTMIN+21 from PID 294 (plymouthd). Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1370]: Setting RT Priority for mpd Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1386]: pid 35's current scheduling policy: SCHED_OTHER Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1386]: pid 35's current scheduling priority: 0 Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1370]: Setting MPD Affinity Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1387]: pid 3's current affinity mask: f Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1370]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 18 17:54:13 volumio-4 volumio-cpu-tweak[1370]: VOLUMIO CPU TWEAK: Setting CPU Governor: conservative Jun 18 17:54:13 volumio-4 systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Jun 18 17:54:13 volumio-4 systemd[1]: Received SIGRTMIN+21 from PID 294 (plymouthd). Jun 18 17:54:13 volumio-4 systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Jun 18 17:54:13 volumio-4 systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Jun 18 17:54:13 volumio-4 systemd[1]: Started serial-getty@ttyAMA10.service - Serial Getty on ttyAMA10. Jun 18 17:54:13 volumio-4 systemd[1]: Reached target getty.target - Login Prompts. Jun 18 17:54:13 volumio-4 systemd[1]: Reached target multi-user.target - Multi-User System. Jun 18 17:54:13 volumio-4 systemd[1]: Reached target graphical.target - Graphical Interface. Jun 18 17:54:13 volumio-4 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Jun 18 17:54:13 volumio-4 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Jun 18 17:54:13 volumio-4 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Jun 18 17:54:13 volumio-4 systemd[1]: Startup finished in 11.239s (kernel) + 15.236s (userspace) = 26.476s. Jun 18 17:54:14 volumio-4 ntpd[1064]: IO: Listen normally on 3 wlan0 192.168.88.191:123 Jun 18 17:54:14 volumio-4 ntpd[1064]: IO: new interface(s) found: waking up resolver Jun 18 17:54:14 volumio-4 ntpd[1064]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:14 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:14 volumio-4 volumio[1355]: info: ----- Volumio3 ---- Jun 18 17:54:14 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:14 volumio-4 volumio[1355]: info: ----- System startup ---- Jun 18 17:54:14 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:14 volumio-4 avahi-daemon[1349]: Server startup complete. Host name is volumio-4.local. Local service cookie is 210269772. Jun 18 17:54:14 volumio-4 volumio[1355]: info: MYVOLUMIO Environment detected Jun 18 17:54:14 volumio-4 volumio[1355]: info: Plugin folders cleanup Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning into folder /volumio/app/plugins/ Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category audio_interface Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category miscellanea Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category music_service Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category plugins.json Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category system_controller Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category user_interface Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning into folder /data/plugins/ Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category music_service Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category system_controller Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category system_hardware Jun 18 17:54:14 volumio-4 volumio[1355]: info: Scanning category user_interface Jun 18 17:54:14 volumio-4 volumio[1355]: info: Plugin folders cleanup completed Jun 18 17:54:14 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:14 volumio-4 volumio[1355]: info: ----- Core plugins startup ---- Jun 18 17:54:14 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:14 volumio-4 volumio[1355]: info: Loading plugins from folder /volumio/app/plugins/ Jun 18 17:54:14 volumio-4 volumio[1355]: info: Adding plugin upnp to MyMusic Plugins Jun 18 17:54:14 volumio-4 volumio[1355]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 18 17:54:14 volumio-4 volumio[1355]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 18 17:54:14 volumio-4 volumio[1355]: info: Loading plugins from folder /data/plugins/ Jun 18 17:54:14 volumio-4 volumio[1355]: info: Loading plugin "system"... Jun 18 17:54:14 volumio-4 volumio[1355]: info: Loading plugin "appearance"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "network"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Refreshing Cached IP Addresses Jun 18 17:54:15 volumio-4 sudo[1408]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 18 17:54:15 volumio-4 sudo[1408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:15 volumio-4 sudo[1408]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:15 volumio-4 sudo[1410]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 18 17:54:15 volumio-4 sudo[1410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:15 volumio-4 sudo[1410]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "services"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "alsa_controller"... Jun 18 17:54:15 volumio-4 sudo[1418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 18 17:54:15 volumio-4 sudo[1418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:15 volumio-4 volumio[1355]: warn: Unable to locate the audio output device Raspberry Pi DAC+. Please configure a valid output device. Jun 18 17:54:15 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "wizard"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "networkfs"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Starting Udev Watcher for removable devices Jun 18 17:54:15 volumio-4 volumio[1355]: info: Ignoring mount for partition: boot Jun 18 17:54:15 volumio-4 volumio[1355]: info: Ignoring mount for partition: volumio Jun 18 17:54:15 volumio-4 volumio[1355]: info: Ignoring mount for partition: volumio_data Jun 18 17:54:15 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "volumio_command_line_client"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "upnp"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: [1750262055125] Starting Upmpd Daemon Jun 18 17:54:15 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "my_music"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "mpd"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "upnp_browser"... Jun 18 17:54:15 volumio-4 avahi-daemon[1349]: Service "Volumio 4" (/services/volumio.service) successfully established. Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "alarm-clock"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "airplay_emulation"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Starting Shairport Sync Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "last_100"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "webradio"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "i2s_dacs"... Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "volumiodiscovery"... Jun 18 17:54:15 volumio-4 volumio[1355]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 18 17:54:15 volumio-4 volumio[1355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 18 17:54:15 volumio-4 volumio[1355]: *** WARNING *** For more information see Jun 18 17:54:15 volumio-4 volumio[1355]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 18 17:54:15 volumio-4 volumio[1355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 18 17:54:15 volumio-4 volumio[1355]: *** WARNING *** For more information see Jun 18 17:54:15 volumio-4 node[1355]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 18 17:54:15 volumio-4 node[1355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 18 17:54:15 volumio-4 node[1355]: *** WARNING *** For more information see Jun 18 17:54:15 volumio-4 node[1355]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 18 17:54:15 volumio-4 node[1355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 18 17:54:15 volumio-4 node[1355]: *** WARNING *** For more information see Jun 18 17:54:15 volumio-4 volumio[1355]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 18 17:54:15 volumio-4 volumio[1355]: info: Discovery: Started advertising with name: Volumio 4 Jun 18 17:54:15 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 18 17:54:15 volumio-4 volumio[1355]: info: Loading plugin "ytmusic"... Jun 18 17:54:16 volumio-4 volumio[1355]: info: Loading plugin "now_playing"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "outputs"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "albumart"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Plugin example_plugin is not enabled Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "inputs"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "updater_comm"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Plugin mpdemulation is not enabled Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "rest_api"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "websocket"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Starting Socket.io Server version 1.7.4 Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "backup_restore"... Jun 18 17:54:17 volumio-4 volumio[1440]: Forking 3 albumart workers Jun 18 17:54:17 volumio-4 volumio[1355]: info: Applying required configuration parameters for plugin backup_restore Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "gpio_control"... Jun 18 17:54:17 volumio-4 volumio[1355]: gpiox_arm32 V2.2.1 Jun 18 17:54:17 volumio-4 ntpd[1064]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jun 18 17:54:17 volumio-4 ntpd[1064]: DNS: Pool taking: 195.90.182.235 Jun 18 17:54:17 volumio-4 ntpd[1064]: DNS: Pool taking: 185.175.56.95 Jun 18 17:54:17 volumio-4 ntpd[1064]: DNS: Pool taking: 150.241.82.187 Jun 18 17:54:17 volumio-4 ntpd[1064]: DNS: Pool taking: 178.62.250.107 Jun 18 17:54:17 volumio-4 ntpd[1064]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jun 18 17:54:17 volumio-4 volumio[1450]: Starting albumart workers Jun 18 17:54:17 volumio-4 volumio[1452]: Starting albumart workers Jun 18 17:54:17 volumio-4 volumio[1451]: Starting albumart workers Jun 18 17:54:17 volumio-4 volumio[1355]: info: Applying required configuration parameters for plugin gpio_control Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "ir_controller"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Applying required configuration parameters for plugin ir_controller Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "rotaryencoder2"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading plugin "touch_display"... Jun 18 17:54:17 volumio-4 volumio[1355]: info: Applying required configuration parameters for plugin touch_display Jun 18 17:54:17 volumio-4 volumio[1355]: info: Loading i18n strings for locale en Jun 18 17:54:17 volumio-4 volumio[1355]: Updating browse sources language Jun 18 17:54:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::initPlayerControls Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: Express server listening on port 3000 Jun 18 17:54:18 volumio-4 volumio[1355]: [Metrics] WebUI: 3s 857.85ms Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::resetVolumioState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::getcurrentVolume Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioRetrievevolume Jun 18 17:54:18 volumio-4 volumio[1355]: info: Volumio Network Manager: Network status updated: 2 Jun 18 17:54:18 volumio-4 volumio[1355]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '2'. Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jun 18 17:54:18 volumio-4 volumio[1355]: info: VolumeController:: Volume=undefined Mute =false Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::updateTrackBlock Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrackBlock Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioRetrievevolume Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191:3000 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: Reloading queue from file Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jun 18 17:54:18 volumio-4 volumio[1355]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '2'. Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::setRepeat null single undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::setRandom null Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: Setting Device type: Raspberry PI Jun 18 17:54:18 volumio-4 volumio[1355]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 18 17:54:18 volumio-4 volumio[1355]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Jun 18 17:54:18 volumio-4 volumio[1355]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191:3000 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jun 18 17:54:18 volumio-4 volumio[1355]: info: Completed loading Core Plugins Jun 18 17:54:18 volumio-4 volumio[1355]: info: Preparing to generate the ALSA configuration file Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 18 17:54:18 volumio-4 volumio[1355]: info: VolumeController:: Volume=undefined Mute =false Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 18 17:54:18 volumio-4 ntpd[1064]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:18 volumio-4 volumio[1355]: info: Asound.conf file unchanged, so no further update is needed Jun 18 17:54:18 volumio-4 volumio[1355]: info: Output device has changed, restarting MPD Jun 18 17:54:18 volumio-4 volumio[1355]: info: Output device has changed, restarting Shairport Sync Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 sudo[1517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 18 17:54:18 volumio-4 sudo[1517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 18 17:54:18 volumio-4 sudo[1519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1517]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 volumio[1355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: ___________ START PLUGINS ___________ Jun 18 17:54:18 volumio-4 volumio[1355]: info: ControllerMpd::onStart: Initializing MPD Jun 18 17:54:18 volumio-4 volumio[1355]: info: Creating MPD Configuration file Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 18 17:54:18 volumio-4 volumio[1355]: info: [1750262058137] CoreMusicLibrary::Adding element Media Servers Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 sudo[1527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 18 17:54:18 volumio-4 sudo[1527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 18 17:54:18 volumio-4 sudo[1529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1527]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 volumio[1355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 18 17:54:18 volumio-4 volumio[1355]: info: [1750262058154] CoreMusicLibrary::Adding element Last_100 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 18 17:54:18 volumio-4 volumio[1355]: info: [1750262058155] CoreMusicLibrary::Adding element Webradio Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:54:18 volumio-4 volumio[1355]: info: Initializing BBC Radios Jun 18 17:54:18 volumio-4 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 18 17:54:18 volumio-4 setdatetime-helper.sh[1530]: Time is already synchronized. Jun 18 17:54:18 volumio-4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 18 17:54:18 volumio-4 systemd[1]: Starting mpd.service - Music Player Daemon... Jun 18 17:54:18 volumio-4 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 18 17:54:18 volumio-4 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 18 17:54:18 volumio-4 systemd[1]: mpd.service: Deactivated successfully. Jun 18 17:54:18 volumio-4 systemd[1]: Stopped mpd.service - Music Player Daemon. Jun 18 17:54:18 volumio-4 systemd[1]: mpd.socket: Deactivated successfully. Jun 18 17:54:18 volumio-4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jun 18 17:54:18 volumio-4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jun 18 17:54:18 volumio-4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 systemd[1]: Starting mpd.service - Music Player Daemon... Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 18 17:54:18 volumio-4 volumio[1355]: info: [1750262058194] CoreMusicLibrary::Adding element YouTube Music Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: Cannot find translation for source YouTube Music Jun 18 17:54:18 volumio-4 volumio[1355]: info: [now-playing] ConfigUpdater: config is up to date. Jun 18 17:54:18 volumio-4 volumio[1355]: info: Loading i18n strings for locale en Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:54:18 volumio-4 volumio[1355]: info: Loading i18n strings for locale en Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:54:18 volumio-4 volumio[1355]: info: Volumio Calling Home Jun 18 17:54:18 volumio-4 sudo[1559]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 18 17:54:18 volumio-4 sudo[1559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 18 17:54:18 volumio-4 sudo[1562]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jun 18 17:54:18 volumio-4 sudo[1559]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 sudo[1569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/irexec.lircrc /etc/lirc/lirc_options.conf /etc/lirc/lircd.conf /etc/lirc/lircd.conf.d /etc/lirc/lircmd.conf /etc/lirc/lircrc Jun 18 17:54:18 volumio-4 sudo[1569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jun 18 17:54:18 volumio-4 sudo[1571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1569]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 sudo[1573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jun 18 17:54:18 volumio-4 sudo[1575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jun 18 17:54:18 volumio-4 sudo[1575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 systemd[1]: Reloading. Jun 18 17:54:18 volumio-4 volumio[1355]: info: [now-playing] App is listening on port 4004. Jun 18 17:54:18 volumio-4 volumio[1355]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191:3000 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jun 18 17:54:18 volumio-4 volumio[1355]: info: touch_display: No backlight interface detected. Jun 18 17:54:18 volumio-4 volumio[1355]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Jun 18 17:54:18 volumio-4 volumio[1355]: info: MPD Permissions set Jun 18 17:54:18 volumio-4 volumio[1355]: info: MPD Permissions set Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191:3000 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:54:18 volumio-4 volumio[1355]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Jun 18 17:54:18 volumio-4 sudo[1613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jun 18 17:54:18 volumio-4 volumio[1355]: info: Starting Shairport Sync Jun 18 17:54:18 volumio-4 sudo[1613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jun 18 17:54:18 volumio-4 sudo[1615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 volumio[1355]: info: Starting Shairport Sync Jun 18 17:54:18 volumio-4 sudo[1615]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 volumio[1355]: info: Starting Shairport Sync Jun 18 17:54:18 volumio-4 sudo[1613]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 volumio[1355]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Jun 18 17:54:18 volumio-4 volumio[1355]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jun 18 17:54:18 volumio-4 sudo[1621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 18 17:54:18 volumio-4 sudo[1621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 18 17:54:18 volumio-4 sudo[1623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 18 17:54:18 volumio-4 sudo[1620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 volumio[1355]: info: ir_controller: LIRC correctly updated. Jun 18 17:54:18 volumio-4 volumio[1355]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Jun 18 17:54:18 volumio-4 volumio[1355]: info: ir_controller: Raspberry Pi revision code: d04170 Jun 18 17:54:18 volumio-4 sudo[1632]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Jun 18 17:54:18 volumio-4 sudo[1632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1632]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 sudo[1639]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=25 gpio_pull=up Jun 18 17:54:18 volumio-4 sudo[1639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 sudo[1639]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 volumio[1355]: info: ir_controller: Overlay gpio-ir gpio_pin=25 gpio_pull=up loaded. Jun 18 17:54:18 volumio-4 sudo[1646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Jun 18 17:54:18 volumio-4 sudo[1646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 kernel: Registered IR keymap rc-rc6-mce Jun 18 17:54:18 volumio-4 kernel: IR RC6 protocol handler initialized Jun 18 17:54:18 volumio-4 kernel: rc rc2: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc2 Jun 18 17:54:18 volumio-4 kernel: rc rc2: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Jun 18 17:54:18 volumio-4 kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc2/input5 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 18 17:54:18 volumio-4 volumio[1355]: info: Discovery: Getting this device information Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 sudo[1575]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: Listing playlists Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetVisibleSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: Listing playlists Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetVisibleSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: touch_display: systemctl daemon-reload succeeded. Jun 18 17:54:18 volumio-4 sudo[1418]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:18 volumio-4 (udev-worker)[1648]: event5: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 18 17:54:18 volumio-4 systemd-logind[887]: Watching system buttons on /dev/input/event5 (gpio_ir_recv) Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 sudo[1657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jun 18 17:54:18 volumio-4 sudo[1657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:18 volumio-4 systemd[1]: Reloading. Jun 18 17:54:18 volumio-4 volumio[1355]: info: Listing playlists Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetVisibleSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: Listing playlists Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreStateMachine::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getQueue Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetVisibleSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:18 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:18 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:19 volumio-4 sudo[1573]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jun 18 17:54:19 volumio-4 systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Jun 18 17:54:19 volumio-4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 18 17:54:19 volumio-4 systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Jun 18 17:54:19 volumio-4 sudo[1657]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 systemd[1]: shairport-sync.service: Deactivated successfully. Jun 18 17:54:19 volumio-4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 18 17:54:19 volumio-4 systemd[1]: shairport-sync.service: Consumed 1.521s CPU time. Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: Volumio Kiosk started. Jun 18 17:54:19 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:19 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:19 volumio-4 sudo[1571]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jun 18 17:54:19 volumio-4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 18 17:54:19 volumio-4 sudo[1621]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 sudo[1620]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 sudo[1623]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 volumio[1355]: info: Shairport-Sync Started Jun 18 17:54:19 volumio-4 volumio[1355]: Error adding Membership: Error: addMembership EINVAL Jun 18 17:54:19 volumio-4 volumio[1355]: info: Shairport-Sync Started Jun 18 17:54:19 volumio-4 volumio[1355]: info: Shairport-Sync Started Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: X display number found: Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: X display number found: 0 Jun 18 17:54:19 volumio-4 startx[1718]: X.Org X Server 1.21.1.7 Jun 18 17:54:19 volumio-4 startx[1718]: X Protocol Version 11, Revision 0 Jun 18 17:54:19 volumio-4 startx[1718]: Current Operating System: Linux volumio-4 6.12.27-v8+ #1876 SMP PREEMPT Tue May 6 15:12:28 BST 2025 aarch64 Jun 18 17:54:19 volumio-4 startx[1718]: Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe cgroup_disable=memory numa_policy=interleave numa=fake=8 system_heap.max_order=0 smsc95xx.macaddr=2C:CF:67:8D:B7:8D vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA10,115200 console=tty1 imgpart=UUID=aad31cad-393a-4fed-8407-009f0f1afa8c imgfile=/volumio_current.sqsh bootpart=UUID=3B14-9250 datapart=UUID=1039c36d-c049-4f15-b227-4d4e96b781b2 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jun 18 17:54:19 volumio-4 startx[1718]: xorg-server 2:21.1.7-3+rpt3+deb12u9 (https://www.debian.org/support) Jun 18 17:54:19 volumio-4 startx[1718]: Current version of pixman: 0.44.0 Jun 18 17:54:19 volumio-4 startx[1718]: Before reporting problems, check http://wiki.x.org Jun 18 17:54:19 volumio-4 startx[1718]: to make sure that you have the latest version. Jun 18 17:54:19 volumio-4 startx[1718]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 18 17:54:19 volumio-4 startx[1718]: (++) from command line, (!!) notice, (II) informational, Jun 18 17:54:19 volumio-4 startx[1718]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 18 17:54:19 volumio-4 startx[1718]: (==) Log file: "/var/log/Xorg.0.log", Time: Wed Jun 18 17:54:19 2025 Jun 18 17:54:19 volumio-4 startx[1718]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jun 18 17:54:19 volumio-4 startx[1718]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jun 18 17:54:19 volumio-4 volumio[1355]: info: touch_display: X display number found: 0 Jun 18 17:54:19 volumio-4 sudo[1724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Jun 18 17:54:19 volumio-4 sudo[1724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:19 volumio-4 lircd-setup[1676]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Jun 18 17:54:19 volumio-4 lircd-setup[1676]: parser = configparser.SafeConfigParser() Jun 18 17:54:19 volumio-4 systemd[1]: lircd-setup.service: Deactivated successfully. Jun 18 17:54:19 volumio-4 systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Jun 18 17:54:19 volumio-4 systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: lircd: Opening log, level: Info Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Version: lircd 0.10.1 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: System info: Linux volumio-4 6.12.27-v8+ #1876 SMP PREEMPT Tue May 6 15:12:28 BST 2025 aarch64 GNU/Linux Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: Initial device: /dev/lirc0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: 'lirc' written to protocols file /sys/class/rc/rc2/protocols Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: Initial device: /dev/lirc0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: [lirc] protocol is enabled Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Info: lircd: Opening log, level: Info Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Notice: Using systemd fd Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Warning: Running as root Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: driver: default Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Info: Using remote: lircd.conf. Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: output: /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: nodaemon: 1 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Jun 18 17:54:19 volumio-4 systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: logfile: syslog Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: immediate-init: 0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: permission: 666 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: driver-options: Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: listen: 0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: connect: (null) Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: userelease: 0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: effective_user: (null) Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: release_suffix: _EVUP Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: allow_simulate: 0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: repeat_max: 600 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: configfile: /etc/lirc/lircd.conf Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Options: dynamic_codes: (null) Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Current driver: default Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Driver API version: 3 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Driver version: 0.10.0 Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: lircd: Opening log, level: Info Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: Using systemd fd Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Warning: Running as root Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: Using remote: lircd.conf. Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 sudo[1646]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 sudo[1724]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 volumio[1355]: info: ir_controller: systemctl restart lircd.service succeeded. Jun 18 17:54:19 volumio-4 volumio[1355]: info: ir_controller: systemctl restart lircd.service succeeded. Jun 18 17:54:19 volumio-4 sudo[1730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Jun 18 17:54:19 volumio-4 sudo[1730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:19 volumio-4 sudo[1732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Jun 18 17:54:19 volumio-4 sudo[1732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:19 volumio-4 systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Jun 18 17:54:19 volumio-4 sudo[1730]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Notice: accepted new client on /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: accepted new client on /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Info: [lirc] protocol is enabled Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Info: removed client Jun 18 17:54:19 volumio-4 volumio[1355]: info: ir_controller: systemctl restart irexec.service succeeded. Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: [lirc] protocol is enabled Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: removed client Jun 18 17:54:19 volumio-4 systemd[1]: Stopping irexec.service - Handle events from IR remotes decoded by lircd(8)... Jun 18 17:54:19 volumio-4 systemd[1]: irexec.service: Deactivated successfully. Jun 18 17:54:19 volumio-4 systemd[1]: Stopped irexec.service - Handle events from IR remotes decoded by lircd(8). Jun 18 17:54:19 volumio-4 systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Notice: accepted new client on /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 lircd[1726]: lircd-0.10.1[1726]: Info: [lirc] protocol is enabled Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Notice: accepted new client on /var/run/lirc/lircd Jun 18 17:54:19 volumio-4 lircd-0.10.1[1726]: Info: [lirc] protocol is enabled Jun 18 17:54:19 volumio-4 sudo[1732]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:19 volumio-4 volumio[1355]: info: ir_controller: systemctl restart irexec.service succeeded. Jun 18 17:54:20 volumio-4 volumio[1355]: verbose: New Socket.io Connection to 192.168.88.191 from 192.168.88.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Jun 18 17:54:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:20 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:20 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 18 17:54:20 volumio-4 volumio[1355]: info: Listing playlists Jun 18 17:54:20 volumio-4 mpd[1564]: 2025-06-18T17:54:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 18 17:54:20 volumio-4 systemd[1]: Started mpd.service - Music Player Daemon. Jun 18 17:54:20 volumio-4 sudo[1519]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:20 volumio-4 sudo[1529]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:20 volumio-4 volumio[1355]: info: Completed starting Core Plugins Jun 18 17:54:20 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:20 volumio-4 volumio[1355]: info: ----- MyVolumio plugins startup ---- Jun 18 17:54:20 volumio-4 volumio[1355]: info: ------------------------------------------- Jun 18 17:54:20 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 18 17:54:20 volumio-4 volumio[1355]: error: MPD error: The expression evaluated to a falsy value: Jun 18 17:54:20 volumio-4 volumio[1355]: assert.ok(self.idling) Jun 18 17:54:20 volumio-4 volumio[1355]: error: The expression evaluated to a falsy value: Jun 18 17:54:20 volumio-4 volumio[1355]: assert.ok(self.idling) Jun 18 17:54:20 volumio-4 volumio[1355]: error: updateQueue error: null Jun 18 17:54:20 volumio-4 volumio[1355]: info: MPD running with PID1564 Jun 18 17:54:20 volumio-4 volumio[1355]: ,establishing connection Jun 18 17:54:20 volumio-4 volumio[1355]: error: updateQueue error: null Jun 18 17:54:20 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:20 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:20 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:20 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:20 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:21 volumio-4 kernel: EDID block 0 (tag 0x00) checksum is invalid, remainder is 11 Jun 18 17:54:21 volumio-4 volumio[1355]: info: touch_display: Setting screensaver timeout to 541 seconds. Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 79.133.44.143 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 217.198.219.102 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 37.1.205.111 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 51.15.191.239 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 2001:ba0:252:ee00::123 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 2a03:38a0:60:123::1 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 2001:67c:20d0:aad::acad:123 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: Pool taking: 2001:ac8:26:62:0:1:0:21 Jun 18 17:54:21 volumio-4 ntpd[1064]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jun 18 17:54:21 volumio-4 volumio[1355]: info: Volumio called home Jun 18 17:54:22 volumio-4 ntpd[1064]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:46 volumio-4 ntpd[1064]: CLOCK: time stepped by 23.427829 Jun 18 17:54:46 volumio-4 ntpd[1064]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jun 18 17:54:46 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:46] [connect] Successful connection Jun 18 17:54:46 volumio-4 volumio-remote-updater[892]: [2025-06-18 17:54:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1750262086 101 Jun 18 17:54:46 volumio-4 volumio[1355]: 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: 12 Jun 18 17:54:47 volumio-4 volumio[1355]: info: Discovery: adding 4a0f961e-3558-48a7-aa8a-8143f3c5b83f Jun 18 17:54:47 volumio-4 volumio[1355]: info: Discovery: Found device Volumio 4 Jun 18 17:54:47 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:47 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:47 volumio-4 volumio[1355]: info: Discovery: this is already registered, 4a0f961e-3558-48a7-aa8a-8143f3c5b83f Jun 18 17:54:47 volumio-4 volumio[1355]: info: Discovery: Found device Volumio 4 Jun 18 17:54:47 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:47 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:47 volumio-4 volumio[1355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Jun 18 17:54:47 volumio-4 volumio[1355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Jun 18 17:54:47 volumio-4 ntpd[1064]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jun 18 17:54:47 volumio-4 ntpd[1064]: DNS: Pool taking: 194.58.207.148 Jun 18 17:54:47 volumio-4 ntpd[1064]: DNS: Pool taking: 212.132.97.26 Jun 18 17:54:47 volumio-4 ntpd[1064]: DNS: Pool taking: 45.90.217.6 Jun 18 17:54:47 volumio-4 ntpd[1064]: DNS: Pool taking: 83.212.117.131 Jun 18 17:54:47 volumio-4 ntpd[1064]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jun 18 17:54:47 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:47 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:48 volumio-4 volumio[1355]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not access weather service: missing geographic coordinates. Jun 18 17:54:48 volumio-4 volumio[1355]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:95:19) Jun 18 17:54:48 volumio-4 volumio[1355]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:116:37) Jun 18 17:54:48 volumio-4 volumio[1355]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:51:13 Jun 18 17:54:48 volumio-4 volumio[1355]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Jun 18 17:54:48 volumio-4 volumio[1355]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:149:13) Jun 18 17:54:48 volumio-4 volumio[1355]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:119:3) Jun 18 17:54:48 volumio-4 volumio[1355]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Jun 18 17:54:48 volumio-4 volumio[1355]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Jun 18 17:54:48 volumio-4 volumio[1355]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Jun 18 17:54:48 volumio-4 volumio[1355]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Jun 18 17:54:48 volumio-4 volumio[1355]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Jun 18 17:54:48 volumio-4 volumio[1355]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Jun 18 17:54:48 volumio-4 volumio[1355]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Jun 18 17:54:48 volumio-4 volumio[1355]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Jun 18 17:54:48 volumio-4 volumio[1355]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Jun 18 17:54:48 volumio-4 volumio[1355]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Jun 18 17:54:48 volumio-4 volumio[1355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15 Jun 18 17:54:48 volumio-4 volumio[1355]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 18 17:54:48 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 18 17:54:48 volumio-4 volumio[1355]: info: Listing playlists Jun 18 17:54:48 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetQueue Jun 18 17:54:48 volumio-4 volumio[1355]: info: CoreStateMachine::getQueue Jun 18 17:54:48 volumio-4 volumio[1355]: info: CorePlayQueue::getQueue Jun 18 17:54:48 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetVisibleSources Jun 18 17:54:48 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 18 17:54:48 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:48 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:48 volumio-4 ntpd[1064]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 18 17:54:48 volumio-4 sudo[1977]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 18 17:54:48 volumio-4 sudo[1977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:48 volumio-4 sudo[1979]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 18 17:54:48 volumio-4 sudo[1979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:48 volumio-4 sudo[1977]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:48 volumio-4 sudo[1979]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:48 volumio-4 sudo[1983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 18 17:54:48 volumio-4 sudo[1983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:48 volumio-4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jun 18 17:54:48 volumio-4 sudo[1983]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:48 volumio-4 volumio[1355]: info: Upmpdcli Daemon Started Jun 18 17:54:48 volumio-4 volumio[1355]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 18 17:54:50 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:50 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:50 volumio-4 volumio[1355]: info: VolumeController::SetAlsaVolume0 Jun 18 17:54:50 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:54:50 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:50 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 17:54:50 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:54:50 volumio-4 volumio[1355]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '2'. Jun 18 17:54:50 volumio-4 ntpd[1064]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jun 18 17:54:50 volumio-4 ntpd[1064]: DNS: Pool taking: 5.34.248.224 Jun 18 17:54:50 volumio-4 ntpd[1064]: DNS: Pool taking: 85.215.189.120 Jun 18 17:54:50 volumio-4 ntpd[1064]: DNS: Pool taking: 87.106.44.149 Jun 18 17:54:50 volumio-4 ntpd[1064]: DNS: Pool taking: 213.239.211.90 Jun 18 17:54:50 volumio-4 ntpd[1064]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jun 18 17:54:52 volumio-4 systemd[1]: systemd-fsckd.service: Deactivated successfully. Jun 18 17:54:53 volumio-4 dhcpcd[827]: timed out Jun 18 17:54:53 volumio-4 sh[811]: timed out Jun 18 17:54:53 volumio-4 sh[764]: ifup: failed to bring up eth0 Jun 18 17:54:53 volumio-4 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 18 17:54:53 volumio-4 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 18 17:54:53 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:53 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:53 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:54:53 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:54 volumio-4 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jun 18 17:54:54 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPlay Jun 18 17:54:54 volumio-4 volumio[1355]: info: CoreStateMachine::play index undefined Jun 18 17:54:54 volumio-4 volumio[1355]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 18 17:54:54 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:54 volumio-4 volumio[1355]: info: CoreStateMachine::startPlaybackTimer Jun 18 17:54:54 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:54:54 volumio-4 volumio[1355]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22The%20Best%20of%20Mozart%22%2C%22artist%22%3A%22ALIBI%20Music%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FRb0UmrCXxVA%2Fhqdefault.jpg%3Fsqp%3D-oaymwEWCMACELQBIAQqCghQEJADGFogjgJIWg%26rs%3DAMzJL3kiTeiRgxasqznYegA9R9ghoRO21A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Rb0UmrCXxVA%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Rb0UmrCXxVA%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%7D%7D Jun 18 17:54:54 volumio-4 volumio[1355]: info: [ytmusic] InnertubeLoader: creating Innertube instance... Jun 18 17:54:55 volumio-4 upmpdcli[2007]: writing RSA key Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 18 17:54:57 volumio-4 volumio[1355]: info: Adding plugin bluetooth to MyMusic Plugins Jun 18 17:54:57 volumio-4 volumio[1355]: info: Adding plugin multiroom to MyMusic Plugins Jun 18 17:54:57 volumio-4 volumio[1355]: info: Adding plugin metavolumio to MyMusic Plugins Jun 18 17:54:57 volumio-4 volumio[1355]: info: Adding plugin cd_controller to MyMusic Plugins Jun 18 17:54:57 volumio-4 volumio[1355]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 18 17:54:57 volumio-4 volumio[1355]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 18 17:54:57 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:57 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:54:57 volumio-4 volumio[1355]: info: Starting MyVolumio Remote Streaming Endpoints Jun 18 17:54:57 volumio-4 volumio[1355]: info: MyVolumio login type: Token Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 18 17:54:57 volumio-4 volumio[1355]: info: Streaming services startup Jun 18 17:54:57 volumio-4 volumio[1355]: info: Starting Streaming Daemon Jun 18 17:54:57 volumio-4 sudo[2012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 18 17:54:57 volumio-4 sudo[2012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:54:57 volumio-4 volumio[1355]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 18 17:54:57 volumio-4 sudo[2012]: pam_unix(sudo:session): session closed for user root Jun 18 17:54:57 volumio-4 volumio[1355]: error: Cannot start Volumio Streaming Daemon Jun 18 17:54:57 volumio-4 volumio[1355]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 18 17:54:57 volumio-4 volumio[1355]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 18 17:54:59 volumio-4 volumio[1355]: info: [ytmusic] InnertubeLoader: obtaining po_token by visitorData... Jun 18 17:55:04 volumio-4 volumio[1355]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 18 17:55:04 volumio-4 volumio[1355]: info: [ytmusic] InnertubeLoader: obtained po_token (expires in 43200 seconds) Jun 18 17:55:04 volumio-4 volumio[1355]: info: [ytmusic] InnertubeLoader: re-create Innertube instance with po_token Jun 18 17:55:04 volumio-4 volumio[1355]: info: [ytmusic] InnertubeLoader: creating Innertube instance with po_token... Jun 18 17:55:06 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPlay Jun 18 17:55:06 volumio-4 volumio[1355]: info: CoreStateMachine::play index undefined Jun 18 17:55:06 volumio-4 volumio[1355]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 18 17:55:06 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:06 volumio-4 volumio[1355]: info: CoreStateMachine::startPlaybackTimer Jun 18 17:55:06 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:06 volumio-4 volumio[1355]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22The%20Best%20of%20Mozart%22%2C%22artist%22%3A%22ALIBI%20Music%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FRb0UmrCXxVA%2Fhqdefault.jpg%3Fsqp%3D-oaymwEWCMACELQBIAQqCghQEJADGFogjgJIWg%26rs%3DAMzJL3kiTeiRgxasqznYegA9R9ghoRO21A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Rb0UmrCXxVA%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Rb0UmrCXxVA%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%7D%7D Jun 18 17:55:07 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPlay Jun 18 17:55:07 volumio-4 volumio[1355]: info: CoreStateMachine::play index undefined Jun 18 17:55:07 volumio-4 volumio[1355]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 18 17:55:07 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:07 volumio-4 volumio[1355]: info: CoreStateMachine::startPlaybackTimer Jun 18 17:55:07 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:07 volumio-4 volumio[1355]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22The%20Best%20of%20Mozart%22%2C%22artist%22%3A%22ALIBI%20Music%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FRb0UmrCXxVA%2Fhqdefault.jpg%3Fsqp%3D-oaymwEWCMACELQBIAQqCghQEJADGFogjgJIWg%26rs%3DAMzJL3kiTeiRgxasqznYegA9R9ghoRO21A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Rb0UmrCXxVA%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Rb0UmrCXxVA%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%7D%7D Jun 18 17:55:08 volumio-4 volumio[1355]: info: MyVolumio token set successfully Jun 18 17:55:08 volumio-4 volumio[1355]: info: MYVOLUMIO: Adding device Jun 18 17:55:08 volumio-4 volumio[1355]: info: MYVOLUMIO: Evaluating Server Jun 18 17:55:08 volumio-4 volumio[1355]: info: MyVolumio status changed Jun 18 17:55:08 volumio-4 volumio[1355]: info: Streaming services startup Jun 18 17:55:08 volumio-4 volumio[1355]: info: Starting Streaming Daemon Jun 18 17:55:08 volumio-4 volumio[1355]: info: Removing browser output: myVolumio user plan is not superstar Jun 18 17:55:08 volumio-4 volumio[1355]: info: Removing audio output: Jun 18 17:55:08 volumio-4 volumio[1355]: info: Stoppping Tunnel 1 Jun 18 17:55:08 volumio-4 sudo[2050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 18 17:55:08 volumio-4 sudo[2050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:55:08 volumio-4 sudo[2052]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 18 17:55:08 volumio-4 sudo[2052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 18 17:55:08 volumio-4 sudo[2050]: pam_unix(sudo:session): session closed for user root Jun 18 17:55:08 volumio-4 volumio[1355]: error: Cannot start Volumio Streaming Daemon Jun 18 17:55:08 volumio-4 volumio[1355]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 18 17:55:08 volumio-4 volumio[1355]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 18 17:55:08 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 18 17:55:08 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 18 17:55:08 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 18 17:55:08 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 18 17:55:08 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 18 17:55:08 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 18 17:55:08 volumio-4 sudo[2052]: pam_unix(sudo:session): session closed for user root Jun 18 17:55:08 volumio-4 volumio[1355]: info: Remote SSH Stopped Jun 18 17:55:10 volumio-4 volumio[1355]: info: Setting Geolocation for MyVolumio to eu6 Jun 18 17:55:10 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:10 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:10 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:11 volumio-4 volumio[1355]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 18 17:55:11 volumio-4 systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 18 17:55:11 volumio-4 volumio[1355]: info: Updating MyVolumio device info Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:11 volumio-4 volumio-remote-updater[892]: Test mode disabled Jun 18 17:55:11 volumio-4 volumio-remote-updater[892]: Alpha mode disabled Jun 18 17:55:11 volumio-4 volumio-remote-updater[892]: Alpha legacy test mode disabled Jun 18 17:55:11 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 18 17:55:12 volumio-4 volumio[1355]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 18 17:55:12 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 18 17:55:12 volumio-4 volumio[1355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Jun 18 17:55:12 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetState Jun 18 17:55:12 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:14 volumio-4 volumio[1355]: info: [ytmusic] InnertubeLoader: going to refresh po_token in 43100 seconds Jun 18 17:55:14 volumio-4 volumio[1355]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 18 17:55:14 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 18 17:55:15 volumio-4 volumio[1355]: info: MYVOLUMIO: Adding device Jun 18 17:55:15 volumio-4 volumio[1355]: info: MYVOLUMIO: Evaluating Server Jun 18 17:55:15 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:15 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand stop Jun 18 17:55:15 volumio-4 volumio[1355]: info: sendMpdCommand stop took 0 milliseconds Jun 18 17:55:15 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand clear Jun 18 17:55:15 volumio-4 volumio[1355]: info: sendMpdCommand clear took 1 milliseconds Jun 18 17:55:15 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand addid "https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283714&ei=YuFSaLasC_2OsvQPnMaN4QQ&ip=46.11.181.182&id=o-AARDf5MOYqxPFWP6F_61Uc0pJxrdSRDFcl1mK1T4Co6Y&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262114%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7rn7r&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLNEjzpgW8bJlKJ3m85S2eugoROW3LnmtDCbm3Rqs7DgtL0cGWse-8cDaQxKAYNZJmfW0Vpp0LMq&spc=l3OVKVv7__7YhIN7BnLUccRlKEib4J823CBfdSUgsFdcS8wTdHoIE-wAw5SxNWpNcmw&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=rzNJKPs45ct-YEDGYTSHx4EQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=5&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=wbCiT55JXVg2UQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRgIhAMikhrDPbw5xlSpSMBaDUFFHX1zwNDzoXs1UaQqwdpm4AiEA3YxC1OsM4WKK_cQjHw0AaigLaQvISalz56Y0aP_Qb0Y%3D&sig=AJfQdSswRAIgIroM8LgIvcJ1qfrXJxp_QZVvRsplN38iKd5obVLrRzsCIDw-kXyVNQnGvheqbZW5-fqZG5URBJdHwgv_amTfOFV9&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube" Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: sendMpdCommand addid "https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283714&ei=YuFSaLasC_2OsvQPnMaN4QQ&ip=46.11.181.182&id=o-AARDf5MOYqxPFWP6F_61Uc0pJxrdSRDFcl1mK1T4Co6Y&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262114%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7rn7r&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLNEjzpgW8bJlKJ3m85S2eugoROW3LnmtDCbm3Rqs7DgtL0cGWse-8cDaQxKAYNZJmfW0Vpp0LMq&spc=l3OVKVv7__7YhIN7BnLUccRlKEib4J823CBfdSUgsFdcS8wTdHoIE-wAw5SxNWpNcmw&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=rzNJKPs45ct-YEDGYTSHx4EQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=5&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=wbCiT55JXVg2UQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRgIhAMikhrDPbw5xlSpSMBaDUFFHX1zwNDzoXs1UaQqwdpm4AiEA3YxC1OsM4WKK_cQjHw0AaigLaQvISalz56Y0aP_Qb0Y%3D&sig=AJfQdSswRAIgIroM8LgIvcJ1qfrXJxp_QZVvRsplN38iKd5obVLrRzsCIDw-kXyVNQnGvheqbZW5-fqZG5URBJdHwgv_amTfOFV9&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube" took 2 milliseconds Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 1ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 1ms Jun 18 17:55:15 volumio-4 volumio[1355]: verbose: MPD COMMAND [object Object] Jun 18 17:55:15 volumio-4 volumio[1355]: verbose: MPD COMMAND [object Object] Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 3ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 1ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 1ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 18 17:55:15 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand play Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Jun 18 17:55:15 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:15 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: sendMpdCommand play took 2 milliseconds Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:15 volumio-4 volumio[1355]: info: ------------------------------ 1ms Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioGetBrowseSources Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 18 17:55:17 volumio-4 volumio[1355]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 18 17:55:17 volumio-4 volumio[1355]: info: Completed starting MyVolumio Plugin Jun 18 17:55:17 volumio-4 volumio[1355]: [Metrics] CommandRouter: 40s 117.41ms Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::volumiosetStartupVolume Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::Close All Modals sent Jun 18 17:55:17 volumio-4 volumio[1355]: info: CoreCommandRouter::Close All Modals sent Jun 18 17:55:17 volumio-4 volumio[1355]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Jun 18 17:55:17 volumio-4 volumio[1355]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for DAC Jun 18 17:55:17 volumio-4 volumio[1355]: aplay: main:831: audio open error: No such device Jun 18 17:55:18 volumio-4 volumio[1355]: info: Setting Geolocation for MyVolumio to eu4 Jun 18 17:55:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:18 volumio-4 volumio[1355]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 18 17:55:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 18 17:55:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 18 17:55:18 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 18 17:55:19 volumio-4 volumio[1355]: info: Updating MyVolumio device info Jun 18 17:55:19 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:19 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:19 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 18 17:55:19 volumio-4 volumio[1355]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand stop Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand stop took 63 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand clear Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:20 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:20 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand status took 1 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand clear took 1 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand status took 0 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand status took 1 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand addid "https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283720&ei=aOFSaNIQ1InM-w-_9MrxCg&ip=46.11.181.182&id=o-AL4yiUmKUZu21OMzfH6XvnBF5zzHhVxcRq8l96C6deaB&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262120%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=3140000&bui=AY1jyLOTtOZgJmJP1Yt7JkxjmY1mJ3_73DOOCG7OyXyom346tzUWlHmoRFC3try_unzG_OJpLcRo28Fv&spc=l3OVKfRAfpkyavWVI-WjdX46zdFu8IvKGgC1yv85bdqR3dXWBzUbNbWtZBYHsphIjSE&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=moEFodjEGP4afxpWW5ID3jYQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261777&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=pcnngm6AvpUAeQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIgTMribKEfyi76R0GD2OI8X9yGsO2lLEQrFj6xsiSotQ0CIQDzTL2KTFODw-d_Orz1Bb08FVdUkNGIzWKvnfe8ZNQPbg%3D%3D&sig=AJfQdSswRAIgNymw260t3lAT2dtQ6IId7nNdwsAvIJF5IOzap1uFsQoCIGIDsKkFb9s80R6YEigmWNbpmFQccJXcq5BY8O1EvFf2&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube" Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:20 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:20 volumio-4 volumio[1355]: 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} Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService stop Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: No code Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:20 volumio-4 volumio[1355]: 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} Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService stop Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: No code Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 26ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 25ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: error: updateQueue error: null Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 28ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 27 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand addid "https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283720&ei=aOFSaNIQ1InM-w-_9MrxCg&ip=46.11.181.182&id=o-AL4yiUmKUZu21OMzfH6XvnBF5zzHhVxcRq8l96C6deaB&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262120%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=3140000&bui=AY1jyLOTtOZgJmJP1Yt7JkxjmY1mJ3_73DOOCG7OyXyom346tzUWlHmoRFC3try_unzG_OJpLcRo28Fv&spc=l3OVKfRAfpkyavWVI-WjdX46zdFu8IvKGgC1yv85bdqR3dXWBzUbNbWtZBYHsphIjSE&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=moEFodjEGP4afxpWW5ID3jYQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261777&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=pcnngm6AvpUAeQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIgTMribKEfyi76R0GD2OI8X9yGsO2lLEQrFj6xsiSotQ0CIQDzTL2KTFODw-d_Orz1Bb08FVdUkNGIzWKvnfe8ZNQPbg%3D%3D&sig=AJfQdSswRAIgNymw260t3lAT2dtQ6IId7nNdwsAvIJF5IOzap1uFsQoCIGIDsKkFb9s80R6YEigmWNbpmFQccJXcq5BY8O1EvFf2&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube" took 27 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:20 volumio-4 volumio[1355]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: MPD COMMAND [object Object] Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: MPD COMMAND [object Object] Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 31ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 21ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 18ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 18ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 18 17:55:20 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand play Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Jun 18 17:55:20 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:20 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 5ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: sendMpdCommand play took 4 milliseconds Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 4ms Jun 18 17:55:20 volumio-4 volumio[1355]: info: ------------------------------ 3ms Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand stop took 3 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand clear Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 1 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand clear took 1 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 1 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 0 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand addid "https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube" Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: 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} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: No code Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: 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} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: No code Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 25ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 25ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: error: updateQueue error: null Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 26ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 26 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand addid "https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube" took 26 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 1ms Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: MPD COMMAND [object Object] Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: MPD COMMAND [object Object] Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 29ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 9ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 8ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 7ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand play Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces system playlist update Jun 18 17:55:23 volumio-4 volumio[1355]: info: Ignoring MPD Status Update Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 3ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand play took 2 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 2ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 4 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: info: Jun 18 17:55:23 volumio-4 volumio[1355]: ---------------------------- MPD announces state update: player Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::getState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand status Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 7 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 8 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand clearerror took 5 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 4 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 4 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":6961,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Best of Mozart","artist":"ALIBI Music","album":null,"uri":"https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService pause Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 19ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand status took 17 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand clearerror took 15 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand clearerror took 14 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 12 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseState Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":6961,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Best of Mozart","artist":"ALIBI Music","album":null,"uri":"https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService pause Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":6961,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Best of Mozart","artist":"ALIBI Music","album":null,"uri":"https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService pause Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":6961,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Best of Mozart","artist":"ALIBI Music","album":null,"uri":"https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService pause Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":6961,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Best of Mozart","artist":"ALIBI Music","album":null,"uri":"https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService pause Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 47ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 47ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 47ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 43ms Jun 18 17:55:23 volumio-4 volumio[1355]: info: sendMpdCommand playlistinfo took 24 milliseconds Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: ControllerMpd::parseTrackInfo Jun 18 17:55:23 volumio-4 volumio[1355]: info: ControllerMpd::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::servicePushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CorePlayQueue::getTrack 0 Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":6961,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Best of Mozart","artist":"ALIBI Music","album":null,"uri":"https://rr1---sn-q5u5nugx5h-ha5s.googlevideo.com/videoplayback?expire=1750283723&ei=a-FSaLSkA7bAzPsPg5fAmQg&ip=46.11.181.182&id=o-ABgSxbYh0Hza96--mPvSRLMhh6dU-DsBXHtm05EEOhWE&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1750262123%2C&mh=nU&mm=31%2C29&mn=sn-q5u5nugx5h-ha5s%2Csn-hgn7ynek&ms=au%2Crdu&mv=m&mvi=1&pl=24&rms=au%2Cau&initcwndbps=2971250&bui=AY1jyLPm1O6IMuYItTq6i758qAIOgJLOpdz0Hz0xP_m4-_UgL4HR3G9JRDbWQrLhZNcobVqy0osCrKww&spc=l3OVKVgeR3KoGXpuWycXFLg2dz76MnbApADqVcKi_1it5GsAzLcdLp69iqxSjeimLz4&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=bYf04CnT7o9YFp-OAWGccRsQ&rqh=1&gir=yes&clen=121078870&dur=6961.041&lmt=1725579280377094&mt=1750261532&fvip=2&keepalive=yes&fexp=51466697&c=WEB_REMIX&sefc=1&txp=4532434&n=iDpKnkl-gwt7UA&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhAOTfT8Swm5m2ZwX85wSHlt5loWzfqgfZw3pZFZPQGmV4AiB06DJxFJh40nbqOqSzh4UEV9KARJc2XVeR00fm23f2DQ%3D%3D&sig=AJfQdSswRQIhAL4Op0kkSl1EKgjOhOemELInaRg9NKQpCWqatLszL-_VAiBkGPA7RmUVynu98zB0rO-GLTQvEDBqohRSpD8pxidFhg%3D%3D&pot=MpgB2iDbrE03s1XaHElvvbzVocAXlJLNcWbXVeMTl_5o5SXdfDGqkIL0oFqAUN5ZkVPJiKvKQOmDnv1JB7uqYz_o8dj71apK-eWOJZ5abhpAq-LMgzrrz2TWjG30TuLAam0tHcbCnk6S41oTfmaGDvVXLoPXc8llqteFhQiCV3UhXxOfeXV6gVTRtC7K64A0GF6plTX_jsRHgeI%3D&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jun 18 17:55:23 volumio-4 volumio[1355]: verbose: CURRENT POSITION 0 Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState stateService pause Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::syncState currentStatus stop Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreStateMachine::pushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: CoreCommandRouter::volumioPushState Jun 18 17:55:23 volumio-4 volumio[1355]: info: ------------------------------ 49ms Jun 18 17:55:24 volumio-4 volumio[1355]: info: BOOT COMPLETED Jun 18 17:55:25 volumio-4 volumio[1355]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 18 17:55:25 volumio-4 volumio[1355]: TypeError: fetch failed Jun 18 17:55:25 volumio-4 volumio[1355]: at HTTPClient.fetch (/data/plugins/music_service/ytmusic/node_modules/undici/index.js:112:15) Jun 18 17:55:25 volumio-4 volumio[1355]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 18 17:55:25 volumio-4 volumio[1355]: at async HTTPClient.fetch (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:8350:22) Jun 18 17:55:25 volumio-4 volumio[1355]: at async Actions.stats (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:26251:12) Jun 18 17:55:25 volumio-4 volumio[1355]: at async TrackInfo.addToWatchHistory (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:23293:12) { Jun 18 17:55:25 volumio-4 volumio[1355]: cause: ConnectTimeoutError: Connect Timeout Error Jun 18 17:55:25 volumio-4 volumio[1355]: at onConnectTimeout (/data/plugins/music_service/ytmusic/node_modules/undici/lib/core/connect.js:186:24) Jun 18 17:55:25 volumio-4 volumio[1355]: at /data/plugins/music_service/ytmusic/node_modules/undici/lib/core/connect.js:133:46 Jun 18 17:55:25 volumio-4 volumio[1355]: at Immediate._onImmediate (/data/plugins/music_service/ytmusic/node_modules/undici/lib/core/connect.js:174:9) Jun 18 17:55:25 volumio-4 volumio[1355]: at process.processImmediate (node:internal/timers:478:21) { Jun 18 17:55:25 volumio-4 volumio[1355]: code: 'UND_ERR_CONNECT_TIMEOUT' Jun 18 17:55:25 volumio-4 volumio[1355]: } Jun 18 17:55:25 volumio-4 volumio[1355]: } Jun 18 17:55:25 volumio-4 volumio[1355]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 18 17:55:25 volumio-4 sudo[2153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-18 17:54' Jun 18 17:55:25 volumio-4 sudo[2153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cee9bb5b0ee50e4898478097a64b5c6c77d5a212" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 14 07:24:14 UTC 2025" VOLUMIO_VERSION="4.012" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b365b054264e3ebc2709665da2b5d1ee"