Dec 15 14:59:00 volumio systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... Dec 15 14:59:00 volumio systemd[1]: Mounting run-rpc_pipefs.mount - RPC Pipe File System... Dec 15 14:59:00 volumio systemd[1]: Mounted run-rpc_pipefs.mount - RPC Pipe File System. Dec 15 14:59:00 volumio systemd[1]: Reached target rpc_pipefs.target. Dec 15 14:59:00 volumio systemd[1]: rpc-gssd.service - RPC security service for NFS client and server was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab). Dec 15 14:59:00 volumio systemd[1]: Reached target nfs-client.target - NFS client services. Dec 15 14:59:00 volumio systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Dec 15 14:59:00 volumio systemd[1]: Reached target remote-fs.target - Remote File Systems. Dec 15 14:59:00 volumio systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. Dec 15 14:59:00 volumio systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. Dec 15 14:59:00 volumio systemd[1]: Reached target sysinit.target - System Initialization. Dec 15 14:59:00 volumio systemd[1]: Started apt-daily.timer - Daily apt download activities. Dec 15 14:59:00 volumio systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. Dec 15 14:59:00 volumio systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. Dec 15 14:59:00 volumio systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. Dec 15 14:59:00 volumio systemd[1]: Started fstrim.timer - Discard unused blocks once a week. Dec 15 14:59:00 volumio systemd[1]: Started ntpsec-rotate-stats.timer - Rotate ntpd stats daily. Dec 15 14:59:00 volumio systemd[1]: Started setdatetime-helper.timer - Volumio Time Sync Watchdog Timer. Dec 15 14:59:00 volumio systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Dec 15 14:59:00 volumio systemd[1]: Reached target timers.target - Timer Units. Dec 15 14:59:00 volumio systemd[1]: Listening on avahi-daemon.socket - Avahi mDNS/DNS-SD Stack Activation Socket. Dec 15 14:59:00 volumio systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Dec 15 14:59:00 volumio systemd[1]: Reached target sockets.target - Socket Units. Dec 15 14:59:00 volumio 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). Dec 15 14:59:00 volumio systemd[1]: Reached target basic.target - Basic System. Dec 15 14:59:00 volumio 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). Dec 15 14:59:00 volumio systemd[1]: Starting alsa-restore.service - Save/Restore Sound Card State... Dec 15 14:59:00 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 15 14:59:00 volumio systemd[1]: Starting bluetooth.service - Bluetooth service... Dec 15 14:59:00 volumio systemd[1]: Starting dbus.service - D-Bus System Message Bus... Dec 15 14:59:00 volumio systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... Dec 15 14:59:00 volumio 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). Dec 15 14:59:00 volumio systemd[1]: headless_wireless.service - Copy user wpa_supplicant.conf was skipped because of an unmet condition check (ConditionPathExists=/boot/wpa_supplicant.conf). Dec 15 14:59:00 volumio systemd[1]: Started iptables.service - Volumio Iptables Module. Dec 15 14:59:00 volumio systemd[1]: Starting loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling... Dec 15 14:59:00 volumio systemd[1]: Starting rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates... Dec 15 14:59:00 volumio systemd[1]: Starting systemd-logind.service - User Login Management... Dec 15 14:59:00 volumio systemd[1]: systemd-pcrphase.service - TPM2 PCR Barrier (User) was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f). Dec 15 14:59:00 volumio systemd[1]: Starting triggerhappy.service - triggerhappy global hotkey daemon... Dec 15 14:59:00 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 14:59:00 volumio systemd[1]: Started volumio-remote-updater.service - Volumio Remote OTA Updater. Dec 15 14:59:00 volumio systemd[1]: Starting volumio_rfkill_unblock.service - Manage nl80211 modules blocking state... Dec 15 14:59:00 volumio systemd[1]: volumiossh.service - Volumio SSH enabler was skipped because of an unmet condition check (ConditionPathExistsGlob=/boot/ssh{,.txt}). Dec 15 14:59:00 volumio systemd[1]: Starting wireless.service - Wireless Services... Dec 15 14:59:00 volumio systemd[1]: e2scrub_reap.service: Deactivated successfully. Dec 15 14:59:00 volumio systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. Dec 15 14:59:00 volumio thd[1005]: Unable to parse trigger line: Dec 15 14:59:00 volumio thd[1005]: Unable to parse trigger line: Dec 15 14:59:00 volumio systemd[1]: Started triggerhappy.service - triggerhappy global hotkey daemon. Dec 15 14:59:00 volumio systemd[1]: Starting th-udev-rebind.service - Late rebind of input devices to triggerhappy... Dec 15 14:59:00 volumio volumio_rfkill_unblock.sh[1011]: Volumio WiFi Soft Blocked check script Dec 15 14:59:00 volumio volumio_rfkill_unblock.sh[1011]: Check if rfkill is available Dec 15 14:59:00 volumio volumio_rfkill_unblock.sh[1011]: Check if rfkill listed devices are already unblocked Dec 15 14:59:00 volumio th-udev-rebind.sh[1017]: Rebinding /dev/input/event0 to thd using --add... Dec 15 14:59:00 volumio alsactl[1021]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 15 14:59:00 volumio alsactl[1021]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 15 14:59:00 volumio avahi-daemon[997]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Dec 15 14:59:00 volumio avahi-daemon[997]: Successfully dropped root privileges. Dec 15 14:59:00 volumio avahi-daemon[997]: avahi-daemon 0.8 starting up. Dec 15 14:59:00 volumio systemd[1]: Finished alsa-restore.service - Save/Restore Sound Card State. Dec 15 14:59:00 volumio systemd[1]: Reached target sound.target - Sound Card. Dec 15 14:59:00 volumio th-udev-rebind.sh[1017]: Rebinding /dev/input/event1 to thd using --add... Dec 15 14:59:00 volumio th-udev-rebind.sh[1017]: Rebinding /dev/input/event2 to thd using --add... Dec 15 14:59:00 volumio th-udev-rebind.sh[1017]: Rebinding /dev/input/event3 to thd using --add... Dec 15 14:59:00 volumio th-udev-rebind.sh[1017]: Rebinding /dev/input/event4 to thd using --add... Dec 15 14:59:00 volumio volumio_rfkill_unblock.sh[1011]: Wi-Fi is already unblocked. Dec 15 14:59:00 volumio systemd[1]: Finished volumio_rfkill_unblock.service - Manage nl80211 modules blocking state. Dec 15 14:59:00 volumio systemd[1]: th-udev-rebind.service: Deactivated successfully. Dec 15 14:59:00 volumio systemd[1]: Finished th-udev-rebind.service - Late rebind of input devices to triggerhappy. Dec 15 14:59:00 volumio systemd-logind[1004]: New seat seat0. Dec 15 14:59:00 volumio systemd-logind[1004]: Watching system buttons on /dev/input/event0 (pwr_button) Dec 15 14:59:00 volumio systemd-logind[1004]: Watching system buttons on /dev/input/event1 (vc4-hdmi-0) Dec 15 14:59:00 volumio systemd-logind[1004]: Watching system buttons on /dev/input/event3 (vc4-hdmi-1) Dec 15 14:59:00 volumio systemd[1]: Starting dhcpcd.service - DHCP Client Daemon on all interfaces... Dec 15 14:59:00 volumio rpi-eeprom-update[1003]: WARNING: flashrom not found. Setting RPI_EEPROM_USE_FLASHROM to 0 Dec 15 14:59:00 volumio volumio-remote-updater[1007]: Volumio OTA Client: 1.7.0 Dec 15 14:59:00 volumio volumio-remote-updater[1007]: Error: No active session Dec 15 14:59:00 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:00] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 15 14:59:00 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:00] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 15 14:59:00 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:00] [error] handle_connect error: Connection refused Dec 15 14:59:00 volumio dhcpcd[1033]: dhcpcd-9.4.1 starting Dec 15 14:59:00 volumio loadcpufreq[1002]: Loading cpufreq kernel modules...done (none). Dec 15 14:59:00 volumio systemd[1]: Started loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling. Dec 15 14:59:00 volumio dhcpcd[1052]: dev: loaded udev Dec 15 14:59:00 volumio dhcpcd[1052]: DUID 00:01:00:01:30:c6:00:2b:2c:cf:67:8c:4c:e3 Dec 15 14:59:00 volumio dhcpcd[1052]: dhcp_vendor: No such process Dec 15 14:59:00 volumio dhcpcd[1033]: dhcp_vendor: No such process Dec 15 14:59:00 volumio bluetoothd[998]: Bluetooth daemon 5.83 Dec 15 14:59:00 volumio systemd[1]: Starting cpufrequtils.service - LSB: set CPUFreq kernel parameters... Dec 15 14:59:00 volumio systemd[1]: Started dhcpcd.service - DHCP Client Daemon on all interfaces. Dec 15 14:59:00 volumio dhcpcd[1052]: eth0: waiting for carrier Dec 15 14:59:00 volumio dhcpcd[1052]: wlan0: waiting for carrier Dec 15 14:59:00 volumio systemd[1]: Started dbus.service - D-Bus System Message Bus. Dec 15 14:59:00 volumio upmpdcli[1006]: Could not open config: /tmp/upmpdcli.conf Dec 15 14:59:00 volumio avahi-daemon[997]: Successfully called chroot(). Dec 15 14:59:00 volumio avahi-daemon[997]: Successfully dropped remaining capabilities. Dec 15 14:59:00 volumio dbus-daemon[999]: [system] Successfully activated service 'org.freedesktop.systemd1' Dec 15 14:59:00 volumio bluetoothd[998]: Starting SDP server Dec 15 14:59:00 volumio bluetoothd[998]: Excluding (cli) sap Dec 15 14:59:00 volumio bluetoothd[998]: Excluding (cli) midi Dec 15 14:59:00 volumio bluetoothd[998]: Excluding (cli) battery Dec 15 14:59:00 volumio avahi-daemon[997]: No service file found in /etc/avahi/services. Dec 15 14:59:00 volumio avahi-daemon[997]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 15 14:59:00 volumio avahi-daemon[997]: New relevant interface lo.IPv4 for mDNS. Dec 15 14:59:00 volumio avahi-daemon[997]: Network interface enumeration completed. Dec 15 14:59:00 volumio avahi-daemon[997]: Registering new address record for 127.0.0.1 on lo.IPv4. Dec 15 14:59:00 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Dec 15 14:59:00 volumio kernel: Bluetooth: BNEP filters: protocol multicast Dec 15 14:59:00 volumio kernel: Bluetooth: BNEP socket layer initialized Dec 15 14:59:00 volumio bluetoothd[998]: Bluetooth management interface 1.23 initialized Dec 15 14:59:00 volumio bluetoothd[998]: Battery Provider Manager created Dec 15 14:59:00 volumio dbus-daemon[999]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.1' (uid=0 pid=998 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Dec 15 14:59:00 volumio kernel: Bluetooth: MGMT ver 1.23 Dec 15 14:59:00 volumio systemd[1]: Starting wpa_supplicant.service - WPA supplicant... Dec 15 14:59:00 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:59:00 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 14:59:00 volumio systemd[1]: Started systemd-logind.service - User Login Management. Dec 15 14:59:00 volumio systemd[1]: Started bluetooth.service - Bluetooth service. Dec 15 14:59:00 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 15 14:59:00 volumio systemd[1]: iptables.service: Deactivated successfully. Dec 15 14:59:00 volumio cpufrequtils[1075]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Dec 15 14:59:00 volumio systemd[1]: Starting bluealsa.service - BlueALSA service... Dec 15 14:59:00 volumio kernel: NET: Registered PF_ALG protocol family Dec 15 14:59:00 volumio systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Dec 15 14:59:00 volumio systemd[1]: Started cpufrequtils.service - LSB: set CPUFreq kernel parameters. Dec 15 14:59:00 volumio dbus-daemon[999]: [system] Successfully activated service 'org.freedesktop.hostname1' Dec 15 14:59:00 volumio systemd[1]: Started systemd-hostnamed.service - Hostname Service. Dec 15 14:59:00 volumio wpa_supplicant[1120]: Successfully initialized wpa_supplicant Dec 15 14:59:00 volumio systemd[1]: Started wpa_supplicant.service - WPA supplicant. Dec 15 14:59:00 volumio systemd[1]: Reached target network.target - Network. Dec 15 14:59:00 volumio systemd[1]: Reached target network-online.target - Network is Online. Dec 15 14:59:00 volumio bluetoothd[998]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled Dec 15 14:59:00 volumio bluetoothd[998]: bap: Operation not supported (95) Dec 15 14:59:00 volumio bluetoothd[998]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16 Dec 15 14:59:00 volumio systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically... Dec 15 14:59:00 volumio systemd[1]: Starting nmbd.service - Samba NMB Daemon... Dec 15 14:59:00 volumio systemd[1]: Starting ntpsec.service - Network Time Service... Dec 15 14:59:00 volumio systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... Dec 15 14:59:00 volumio systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart... Dec 15 14:59:00 volumio systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon... Dec 15 14:59:00 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 15 14:59:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 14:59:00 volumio sm-notify[1144]: Version 2.6.2 starting Dec 15 14:59:00 volumio systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Dec 15 14:59:00 volumio systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor. Dec 15 14:59:00 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 15 14:59:00 volumio systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. Dec 15 14:59:00 volumio systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart. Dec 15 14:59:00 volumio systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Dec 15 14:59:00 volumio welcome[1154]: Resolved ip:[0] Dec 15 14:59:00 volumio ifplugd(eth0)[1183]: ifplugd 0.28 initializing. Dec 15 14:59:00 volumio ifplugd(eth0)[1183]: Using interface eth0/2C:CF:67:8C:4C:E3 with driver (version: 6.12.47-v8+) Dec 15 14:59:00 volumio ifplugd(eth0)[1183]: Using detection mode: SIOCETHTOOL Dec 15 14:59:00 volumio ifplugd(eth0)[1183]: Initialization complete, link beat not detected. Dec 15 14:59:00 volumio systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... Dec 15 14:59:00 volumio ntpd[1158]: INIT: ntpd ntpsec-1.2.2: Starting Dec 15 14:59:00 volumio ntp-systemd-wrapper[1158]: 2025-12-15T14:59:00 ntpd[1158]: INIT: ntpd ntpsec-1.2.2: Starting Dec 15 14:59:00 volumio ntp-systemd-wrapper[1158]: 2025-12-15T14:59:00 ntpd[1158]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Dec 15 14:59:00 volumio ntpd[1158]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Dec 15 14:59:00 volumio systemd[1]: Started ntpsec.service - Network Time Service. Dec 15 14:59:00 volumio ntpd[1191]: INIT: precision = 0.370 usec (-21) Dec 15 14:59:00 volumio ntpd[1191]: INIT: successfully locked into RAM Dec 15 14:59:00 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 15 14:59:00 volumio ntpd[1191]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf Dec 15 14:59:00 volumio ntpd[1191]: CONFIG: restrict nopeer ignored Dec 15 14:59:00 volumio ntpd[1191]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Dec 15 14:59:00 volumio ntpd[1191]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2026-06-28T00:00Z last=2017-01-01T00:00Z ofs=37 Dec 15 14:59:00 volumio ntpd[1191]: INIT: Using SO_TIMESTAMPNS(ns) Dec 15 14:59:00 volumio ntpd[1191]: IO: Listen and drop on 0 v6wildcard [::]:123 Dec 15 14:59:00 volumio ntpd[1191]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123 Dec 15 14:59:00 volumio ntpd[1191]: IO: Listen normally on 2 lo 127.0.0.1:123 Dec 15 14:59:00 volumio ntpd[1191]: IO: Listening on routing socket on fd #19 for interface updates Dec 15 14:59:00 volumio ifplugd[1136]: Network Interface Plugging Daemon...start eth0...done. Dec 15 14:59:00 volumio systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Dec 15 14:59:00 volumio ntpd[1191]: INIT: This system has a 32-bit time_t. Dec 15 14:59:00 volumio ntpd[1191]: INIT: This ntpd will fail on 2038-01-19T03:14:07Z. Dec 15 14:59:00 volumio ntpd[1191]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 15 14:59:00 volumio ntpd[1191]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090 Dec 15 14:59:00 volumio ntpd[1191]: INIT: Running with OpenSSL 3.0.17 1 Jul 2025, 30000110 Dec 15 14:59:00 volumio ntpd[1191]: NTSc: Using system default root certificates. Dec 15 14:59:00 volumio rpi-eeprom-update[1003]: BOOTLOADER: up to date Dec 15 14:59:00 volumio rpi-eeprom-update[1003]: CURRENT: Mon Dec 8 19:29:54 UTC 2025 (1765222194) Dec 15 14:59:00 volumio rpi-eeprom-update[1003]: LATEST: Wed Nov 5 17:37:18 UTC 2025 (1762364238) Dec 15 14:59:00 volumio rpi-eeprom-update[1003]: RELEASE: default (/usr/lib/firmware/raspberrypi/bootloader-2712/default) Dec 15 14:59:00 volumio rpi-eeprom-update[1003]: Use raspi-config to change the release. Dec 15 14:59:00 volumio systemd[1]: Finished rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates. Dec 15 14:59:00 volumio ntpd[1191]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory Dec 15 14:59:00 volumio bluealsa[1129]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa Dec 15 14:59:00 volumio bluealsa[1129]: main.c:663: Starting main dispatching loop Dec 15 14:59:00 volumio bluealsa[1129]: main.c:118: Acquired D-Bus service name: org.bluealsa Dec 15 14:59:00 volumio bluealsa[1129]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa Dec 15 14:59:00 volumio systemd[1]: Started bluealsa.service - BlueALSA service. Dec 15 14:59:00 volumio systemd[1]: Reached target bluetooth.target - Bluetooth Support. Dec 15 14:59:00 volumio bluealsa[1129]: bluez.c:153: Registering media application: /org/bluez/hci0 Dec 15 14:59:00 volumio bluealsa[1129]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1 Dec 15 14:59:00 volumio bluealsa[1129]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2 Dec 15 14:59:00 volumio bluealsa[1129]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1 Dec 15 14:59:00 volumio bluealsa[1129]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2 Dec 15 14:59:00 volumio bluetoothd[998]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/2 Dec 15 14:59:00 volumio bluetoothd[998]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/1 Dec 15 14:59:00 volumio bluetoothd[998]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/2 Dec 15 14:59:00 volumio bluetoothd[998]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/1 Dec 15 14:59:01 volumio systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Dec 15 14:59:01 volumio systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Dec 15 14:59:01 volumio avahi-daemon[997]: Server startup complete. Host name is volumio.local. Local service cookie is 1979995961. Dec 15 14:59:01 volumio wireless.js[1013]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 15 14:59:01 volumio wireless.js[1013]: WIRELESS.JS: Wired network status changed to: ---connected--- Dec 15 14:59:01 volumio wireless.js[1013]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 15 14:59:01 volumio nmbd[1235]: [2025/12/15 14:59:01.186452, 0] ../../source3/nmbd/nmbd.c:901(main) Dec 15 14:59:01 volumio nmbd[1235]: nmbd version 4.17.8-Raspbian started. Dec 15 14:59:01 volumio wireless.js[1013]: WIRELESS.JS: Cleaning previous... Dec 15 14:59:01 volumio nmbd[1235]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 15 14:59:01 volumio nmbd[1235]: [2025/12/15 14:59:01.190004, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Dec 15 14:59:01 volumio nmbd[1235]: started asyncdns process 1244 Dec 15 14:59:01 volumio nmbd[1235]: [2025/12/15 14:59:01.190452, 0] ../../lib/util/become_daemon.c:150(daemon_status) Dec 15 14:59:01 volumio nmbd[1235]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Dec 15 14:59:01 volumio nmbd[1235]: [2025/12/15 14:59:01.190479, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Dec 15 14:59:01 volumio nmbd[1235]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Dec 15 14:59:01 volumio sudo[1246]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 15 14:59:01 volumio sudo[1246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:59:01 volumio sudo[1246]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:01 volumio sudo[1248]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 15 14:59:01 volumio sudo[1248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:59:01 volumio ntpd[1191]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:01 volumio ntpd[1191]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 15 14:59:01 volumio ntpd[1191]: DNS: dns_check: DNS error: -11, System error Dec 15 14:59:01 volumio ntpd[1191]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Dec 15 14:59:01 volumio sudo[1248]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:01 volumio wireless.js[1013]: WIRELESS.JS: Stopped aP Dec 15 14:59:01 volumio sudo[1263]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 15 14:59:01 volumio sudo[1263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:01 volumio sudo[1263]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:01 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 15 14:59:01 volumio sudo[1265]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 15 14:59:01 volumio sudo[1265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:01 volumio sudo[1265]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:01 volumio sudo[1273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 15 14:59:01 volumio sudo[1273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:01 volumio sudo[1273]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:01 volumio sudo[1275]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 15 14:59:01 volumio sudo[1275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:02 volumio ntpd[1191]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:02 volumio ntpd[1191]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 15 14:59:02 volumio ntpd[1191]: DNS: dns_check: DNS error: -11, System error Dec 15 14:59:02 volumio ntpd[1191]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Dec 15 14:59:03 volumio dhcpcd[1052]: eth0: carrier acquired Dec 15 14:59:03 volumio sh[899]: eth0: carrier acquired Dec 15 14:59:03 volumio dhcpcd[922]: eth0: carrier acquired Dec 15 14:59:03 volumio kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Dec 15 14:59:03 volumio dhcpcd[1052]: eth0: IAID 67:8c:4c:e3 Dec 15 14:59:03 volumio dhcpcd[922]: eth0: IAID 67:8c:4c:e3 Dec 15 14:59:03 volumio sh[899]: eth0: IAID 67:8c:4c:e3 Dec 15 14:59:03 volumio dhcpcd[1052]: eth0: adding address fe80::66bc:c31c:cd74:5b3c Dec 15 14:59:03 volumio sh[899]: eth0: adding address fe80::66bc:c31c:cd74:5b3c Dec 15 14:59:03 volumio dhcpcd[922]: eth0: adding address fe80::66bc:c31c:cd74:5b3c Dec 15 14:59:03 volumio dhcpcd[1052]: ipv6_addaddr1: Permission denied Dec 15 14:59:03 volumio dhcpcd[922]: ipv6_addaddr1: Permission denied Dec 15 14:59:03 volumio sh[899]: ipv6_addaddr1: Permission denied Dec 15 14:59:03 volumio dhcpcd[922]: eth0: soliciting an IPv6 router Dec 15 14:59:03 volumio sh[899]: eth0: soliciting an IPv6 router Dec 15 14:59:03 volumio dhcpcd[1052]: eth0: soliciting a DHCP lease Dec 15 14:59:03 volumio dhcpcd[1052]: eth0: soliciting an IPv6 router Dec 15 14:59:03 volumio dhcpcd[922]: eth0: soliciting a DHCP lease Dec 15 14:59:03 volumio sh[899]: eth0: soliciting a DHCP lease Dec 15 14:59:03 volumio ntpd[1191]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:03 volumio ntpd[1191]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 15 14:59:03 volumio ntpd[1191]: DNS: dns_check: DNS error: -11, System error Dec 15 14:59:03 volumio ntpd[1191]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Dec 15 14:59:03 volumio ifplugd(eth0)[1183]: Link beat detected. Dec 15 14:59:03 volumio systemd[1]: systemd-rfkill.service: Deactivated successfully. Dec 15 14:59:03 volumio ifplugd(eth0)[1183]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Dec 15 14:59:03 volumio ifplugd(eth0)[1183]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Dec 15 14:59:04 volumio sudo[1275]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:04 volumio wireless.js[1013]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: TH Dec 15 14:59:04 volumio sudo[1306]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 15 14:59:04 volumio sudo[1306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:04 volumio sudo[1306]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:04 volumio sudo[1308]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set TH Dec 15 14:59:04 volumio sudo[1308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:04 volumio sudo[1308]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:04 volumio wireless.js[1013]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: TH Dec 15 14:59:04 volumio wireless.js[1013]: WIRELESS.JS: Single Network Mode: Wired network active, not starting wireless flow Dec 15 14:59:04 volumio wireless.js[1013]: WIRELESS.JS: Notified systemd about wireless ready Dec 15 14:59:04 volumio systemd[1]: Started wireless.service - Wireless Services. Dec 15 14:59:04 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 15 14:59:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:59:04 volumio systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Dec 15 14:59:04 volumio systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Dec 15 14:59:04 volumio systemd[1]: Received SIGRTMIN+21 from PID 405 (plymouthd). Dec 15 14:59:04 volumio ntpd[1191]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:04 volumio ntpd[1191]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 15 14:59:04 volumio ntpd[1191]: DNS: dns_check: DNS error: -11, System error Dec 15 14:59:04 volumio ntpd[1191]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Dec 15 14:59:04 volumio volumio-cpu-tweak[1319]: Setting RT Priority for mpd Dec 15 14:59:04 volumio systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Dec 15 14:59:04 volumio systemd[1]: Received SIGRTMIN+21 from PID 405 (plymouthd). Dec 15 14:59:04 volumio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Dec 15 14:59:04 volumio volumio-cpu-tweak[1339]: pid 35's current scheduling policy: SCHED_OTHER Dec 15 14:59:04 volumio volumio-cpu-tweak[1339]: pid 35's current scheduling priority: 0 Dec 15 14:59:04 volumio volumio-cpu-tweak[1319]: Setting MPD Affinity Dec 15 14:59:04 volumio systemd[1]: Started getty@tty1.service - Getty on tty1. Dec 15 14:59:04 volumio volumio-cpu-tweak[1341]: pid 3's current affinity mask: f Dec 15 14:59:04 volumio systemd[1]: Started serial-getty@ttyAMA10.service - Serial Getty on ttyAMA10. Dec 15 14:59:04 volumio systemd[1]: Reached target getty.target - Login Prompts. Dec 15 14:59:04 volumio volumio-cpu-tweak[1319]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 15 14:59:04 volumio volumio-cpu-tweak[1319]: VOLUMIO CPU TWEAK: Setting CPU Governor: conservative Dec 15 14:59:04 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Dec 15 14:59:05 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:05] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 15 14:59:05 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:05] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 15 14:59:05 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:05] [error] handle_connect error: Connection refused Dec 15 14:59:05 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:05 volumio volumio[1317]: info: ----- Volumio3 ---- Dec 15 14:59:05 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:05 volumio volumio[1317]: info: ----- System startup ---- Dec 15 14:59:05 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:05 volumio dhcpcd[922]: eth0: offered 192.168.1.115 from 192.168.1.1 Dec 15 14:59:05 volumio sh[899]: eth0: offered 192.168.1.115 from 192.168.1.1 Dec 15 14:59:05 volumio dhcpcd[922]: eth0: probing address 192.168.1.115/24 Dec 15 14:59:05 volumio sh[899]: eth0: probing address 192.168.1.115/24 Dec 15 14:59:05 volumio volumio[1317]: info: MYVOLUMIO Environment detected Dec 15 14:59:05 volumio volumio[1317]: info: Plugin folders cleanup Dec 15 14:59:05 volumio volumio[1317]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category audio_interface Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category miscellanea Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category music_service Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category plugins.json Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category system_controller Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category user_interface Dec 15 14:59:05 volumio volumio[1317]: info: Scanning into folder /data/plugins/ Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category music_service Dec 15 14:59:05 volumio volumio[1317]: info: Scanning category user_interface Dec 15 14:59:05 volumio volumio[1317]: info: Plugin folders cleanup completed Dec 15 14:59:05 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:05 volumio volumio[1317]: info: ----- Core plugins startup ---- Dec 15 14:59:05 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:05 volumio volumio[1317]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:59:05 volumio volumio[1317]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:59:05 volumio volumio[1317]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:59:05 volumio volumio[1317]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:59:05 volumio volumio[1317]: info: Loading plugins from folder /data/plugins/ Dec 15 14:59:05 volumio volumio[1317]: info: Loading plugin "system"... Dec 15 14:59:05 volumio bash[1148]: setdatetime-helper: all HTTPS Date fallbacks failed Dec 15 14:59:05 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 15 14:59:05 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 15 14:59:05 volumio volumio[1317]: info: Loading plugin "appearance"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "network"... Dec 15 14:59:06 volumio volumio[1317]: info: Refreshing Cached IP Addresses Dec 15 14:59:06 volumio sudo[1362]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:59:06 volumio sudo[1362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:06 volumio sudo[1364]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:59:06 volumio sudo[1364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:06 volumio sudo[1364]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:06 volumio sudo[1362]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "services"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "alsa_controller"... Dec 15 14:59:06 volumio sudo[1373]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 14:59:06 volumio sudo[1373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:06 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "wizard"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "networkfs"... Dec 15 14:59:06 volumio volumio[1317]: info: Starting Udev Watcher for removable devices Dec 15 14:59:06 volumio sudo[1393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.1.153:/music /mnt/NAS/Truenas Dec 15 14:59:06 volumio sudo[1393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:06 volumio sudo[1395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=egn,password=1022,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.153/music /mnt/NAS/Truenas Dec 15 14:59:06 volumio sudo[1395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:06 volumio sudo[1393]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:06 volumio volumio[1317]: error: Cannot associate FS Label, not mounting Dec 15 14:59:06 volumio volumio[1317]: info: Mounting Device F690F8A190F86A0F Dec 15 14:59:06 volumio kernel: netfs: FS-Cache loaded Dec 15 14:59:06 volumio sudo[1412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/F690F8A190F86A0F -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 15 14:59:06 volumio sudo[1412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:06 volumio kernel: Key type cifs.spnego registered Dec 15 14:59:06 volumio kernel: Key type cifs.idmap registered Dec 15 14:59:06 volumio sudo[1395]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:06 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Dec 15 14:59:06 volumio kernel: CIFS: Attempting to mount //192.168.1.153/music Dec 15 14:59:06 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 15 14:59:06 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Dec 15 14:59:06 volumio ntfs-3g[1424]: Version 2022.10.3 integrated FUSE 28 Dec 15 14:59:06 volumio ntfs-3g[1424]: Mounted /dev/sda2 (Read-Write, label "", NTFS 3.1) Dec 15 14:59:06 volumio ntfs-3g[1424]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 15 14:59:06 volumio ntfs-3g[1424]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda2,blkdev,blksize=4096 Dec 15 14:59:06 volumio ntfs-3g[1424]: Global ownership and permissions enforced, configuration type 7 Dec 15 14:59:06 volumio sudo[1412]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:06 volumio volumio[1317]: info: Ignoring mount for partition: boot Dec 15 14:59:06 volumio volumio[1317]: info: Ignoring mount for partition: volumio Dec 15 14:59:06 volumio volumio[1317]: info: Ignoring mount for partition: volumio_data Dec 15 14:59:06 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "upnp"... Dec 15 14:59:06 volumio volumio[1317]: info: [1765785546398] Starting Upmpd Daemon Dec 15 14:59:06 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "my_music"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "mpd"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "upnp_browser"... Dec 15 14:59:06 volumio volumio[1317]: info: Starting UPNP Browser Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "alarm-clock"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "airplay_emulation"... Dec 15 14:59:06 volumio volumio[1317]: info: Starting Shairport Sync Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "last_100"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "webradio"... Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "i2s_dacs"... Dec 15 14:59:06 volumio volumio[1317]: info: I2S DAC not set, start Auto-detection Dec 15 14:59:06 volumio volumio[1317]: info: Loading plugin "volumiodiscovery"... Dec 15 14:59:06 volumio volumio[1317]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:59:06 volumio volumio[1317]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:59:06 volumio volumio[1317]: *** WARNING *** For more information see Dec 15 14:59:06 volumio volumio[1317]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:59:06 volumio volumio[1317]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:59:06 volumio node[1317]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:59:06 volumio volumio[1317]: *** WARNING *** For more information see Dec 15 14:59:06 volumio node[1317]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:59:06 volumio node[1317]: *** WARNING *** For more information see Dec 15 14:59:06 volumio node[1317]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:59:06 volumio node[1317]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:59:06 volumio node[1317]: *** WARNING *** For more information see Dec 15 14:59:06 volumio volumio[1317]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:59:06 volumio volumio[1317]: info: Discovery: Started advertising with name: Volumio Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "outputs"... Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "albumart"... Dec 15 14:59:07 volumio volumio[1317]: info: Plugin example_plugin is not enabled Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "inputs"... Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "updater_comm"... Dec 15 14:59:07 volumio volumio[1317]: info: Plugin mpdemulation is not enabled Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "rest_api"... Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "websocket"... Dec 15 14:59:07 volumio volumio[1317]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "RoonBridge"... Dec 15 14:59:07 volumio volumio[1428]: Forking 3 albumart workers Dec 15 14:59:07 volumio volumio[1317]: info: Applying required configuration parameters for plugin RoonBridge Dec 15 14:59:07 volumio volumio[1317]: info: Loading plugin "Systeminfo"... Dec 15 14:59:07 volumio volumio[1438]: Starting albumart workers Dec 15 14:59:07 volumio volumio[1439]: Starting albumart workers Dec 15 14:59:07 volumio volumio[1440]: Starting albumart workers Dec 15 14:59:07 volumio volumio[1317]: info: Loading i18n strings for locale en Dec 15 14:59:07 volumio volumio[1317]: Updating browse sources language Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::initPlayerControls Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: Express server listening on port 3000 Dec 15 14:59:07 volumio volumio[1317]: [Metrics] WebUI: 2s 373.01ms Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::resetVolumioState Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::getcurrentVolume Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:07 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: Cannot read play queue from file Dec 15 14:59:07 volumio volumio[1317]: info: Volumio Network Manager: Network status updated: 0 Dec 15 14:59:07 volumio volumio[1317]: info: Cannot mount NAS Truenas at system boot, trial number 1 ,retrying in 5 seconds Dec 15 14:59:07 volumio volumio[1317]: info: Cannot mount NAS Truenas at system boot, trial number 1 ,retrying in 5 seconds Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::setRepeat null single undefined Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:07 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::setRandom null Dec 15 14:59:07 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:07 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:07 volumio volumio[1317]: info: Setting Device type: Raspberry PI Dec 15 14:59:07 volumio volumio[1317]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 14:59:07 volumio volumio[1317]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Dec 15 14:59:07 volumio volumio[1317]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 14:59:07 volumio volumio[1317]: info: Completed loading Core Plugins Dec 15 14:59:07 volumio volumio[1317]: info: Preparing to generate the ALSA configuration file Dec 15 14:59:07 volumio volumio[1317]: info: Asound.conf file written Dec 15 14:59:07 volumio sudo[1501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 15 14:59:07 volumio sudo[1501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio sudo[1501]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio volumio[1317]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 15 14:59:07 volumio volumio[1317]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 15 14:59:07 volumio volumio[1317]: info: Output device has changed, restarting MPD Dec 15 14:59:07 volumio volumio[1317]: info: Output device has changed, restarting Shairport Sync Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio sudo[1507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:59:07 volumio sudo[1507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio volumio[1317]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 14:59:07 volumio volumio[1317]: info: ___________ START PLUGINS ___________ Dec 15 14:59:07 volumio volumio[1317]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:59:07 volumio volumio[1317]: info: Creating MPD Configuration file Dec 15 14:59:07 volumio sudo[1511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:59:07 volumio sudo[1511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio sudo[1507]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio sudo[1517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:59:07 volumio sudo[1517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:59:07 volumio volumio[1317]: info: [1765785547660] CoreMusicLibrary::Adding element Media Servers Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:59:07 volumio sudo[1517]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio volumio[1317]: info: UPNP Browser: Client initialized successfully Dec 15 14:59:07 volumio sudo[1519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:59:07 volumio sudo[1519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:59:07 volumio volumio[1317]: info: [1765785547680] CoreMusicLibrary::Adding element Last_100 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:59:07 volumio volumio[1317]: info: [1765785547681] CoreMusicLibrary::Adding element Webradio Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:59:07 volumio volumio[1317]: info: Initializing BBC Radios Dec 15 14:59:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:59:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:59:07 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:59:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:59:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:59:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:59:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:59:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:59:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: Volumio Calling Home Dec 15 14:59:07 volumio sudo[1548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Dec 15 14:59:07 volumio sudo[1548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio systemd[1]: /lib/systemd/system/roonbridge.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:59:07 volumio systemd[1]: /lib/systemd/system/roonbridge.service:8: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:59:07 volumio sudo[1541]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:59:07 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:59:07 volumio sudo[1554]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 15 14:59:07 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio systemd[1]: Started roonbridge.service - RoonBridge. Dec 15 14:59:07 volumio sudo[1548]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio volumio[1317]: Unhandled rejection Error: No sockets available, cannot start. Dec 15 14:59:07 volumio volumio[1317]: at SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 15 14:59:07 volumio volumio[1317]: at SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 15 14:59:07 volumio volumio[1317]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 15 14:59:07 volumio volumio[1317]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 15 14:59:07 volumio volumio[1317]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 15 14:59:07 volumio volumio[1317]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 15 14:59:07 volumio volumio[1317]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 15 14:59:07 volumio volumio[1317]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 15 14:59:07 volumio volumio[1317]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:156:14) Dec 15 14:59:07 volumio volumio[1317]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 15 14:59:07 volumio volumio[1317]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 15 14:59:07 volumio volumio[1317]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 15 14:59:07 volumio volumio[1317]: at proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 15 14:59:07 volumio volumio[1317]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 15 14:59:07 volumio volumio[1317]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 15 14:59:07 volumio volumio[1317]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 15 14:59:07 volumio volumio[1317]: info: MPD Permissions set Dec 15 14:59:07 volumio volumio[1317]: info: MPD Permissions set Dec 15 14:59:07 volumio volumio[1317]: info: Discovery: adding 1400cf76-61cb-40c3-a26e-621f3ea73bdf Dec 15 14:59:07 volumio volumio[1317]: info: Discovery: Found device Volumio Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:07 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:07 volumio volumio[1317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:07 volumio volumio[1317]: info: Starting Shairport Sync Dec 15 14:59:07 volumio volumio[1317]: info: Starting Shairport Sync Dec 15 14:59:07 volumio volumio[1317]: info: Starting Shairport Sync Dec 15 14:59:07 volumio sudo[1579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 14:59:07 volumio sudo[1579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio sudo[1577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 14:59:07 volumio sudo[1581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 14:59:07 volumio sudo[1581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio sudo[1577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:07 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 14:59:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 14:59:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 14:59:07 volumio systemd[1]: shairport-sync.service: Consumed 1.602s CPU time. Dec 15 14:59:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 14:59:07 volumio sudo[1581]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio sudo[1577]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:07 volumio sudo[1579]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:08 volumio volumio[1317]: info: Shairport-Sync Started Dec 15 14:59:08 volumio volumio[1317]: Error adding Membership: Error: addMembership EINVAL Dec 15 14:59:08 volumio volumio[1317]: info: Shairport-Sync Started Dec 15 14:59:08 volumio volumio[1317]: info: Shairport-Sync Started Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.003 Warn: get lock file path: /tmp/.rnbgem0- Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.145 Trace: [childprocess] using unix child process Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.165 Debug: PathForResource, filename: ../.update Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.214 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.216 Debug: PathForResource, filename: RAATServer Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.216 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.216 Debug: PathForResource, filename: RoonBridgeHelper Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.216 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Dec 15 14:59:08 volumio RoonBridge[1558]: Initializing Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.229 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Dec 15 14:59:08 volumio RoonBridge[1558]: 00:00:00.243 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Dec 15 14:59:08 volumio RoonBridge[1558]: Not Running (.o) Dec 15 14:59:08 volumio RoonBridge[1558]: Running Dec 15 14:59:08 volumio sudo[1373]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:08 volumio RoonBridge[1607]: 00:00:00.008 Warn: get lock file path: /tmp/.rnbhgem0- Dec 15 14:59:09 volumio dhcpcd[1052]: eth0: offered 192.168.1.115 from 192.168.1.1 Dec 15 14:59:09 volumio dhcpcd[1052]: eth0: probing address 192.168.1.115/24 Dec 15 14:59:09 volumio mpd[1555]: 2025-12-15T14:59:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:59:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:59:09 volumio sudo[1511]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:09 volumio sudo[1519]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:09 volumio volumio[1317]: info: Completed starting Core Plugins Dec 15 14:59:09 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:09 volumio volumio[1317]: info: ----- MyVolumio plugins startup ---- Dec 15 14:59:09 volumio volumio[1317]: info: ------------------------------------------- Dec 15 14:59:09 volumio volumio[1317]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:59:09 volumio volumio[1317]: info: MPD running with PID1555 Dec 15 14:59:09 volumio volumio[1317]: ,establishing connection Dec 15 14:59:09 volumio volumio[1317]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:59:09 volumio volumio[1317]: assert.ok(self.idling) Dec 15 14:59:09 volumio volumio[1317]: error: The expression evaluated to a falsy value: Dec 15 14:59:09 volumio volumio[1317]: assert.ok(self.idling) Dec 15 14:59:09 volumio volumio[1317]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:59:09 volumio volumio[1317]: assert.ok(self.idling) Dec 15 14:59:09 volumio volumio[1317]: error: The expression evaluated to a falsy value: Dec 15 14:59:09 volumio volumio[1317]: assert.ok(self.idling) Dec 15 14:59:09 volumio volumio[1317]: error: updateQueue error: null Dec 15 14:59:10 volumio dhcpcd[922]: eth0: leased 192.168.1.115 for 86400 seconds Dec 15 14:59:10 volumio sh[899]: eth0: leased 192.168.1.115 for 86400 seconds Dec 15 14:59:10 volumio sh[899]: eth0: adding route to 192.168.1.0/24 Dec 15 14:59:10 volumio avahi-daemon[997]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.115. Dec 15 14:59:10 volumio avahi-daemon[997]: New relevant interface eth0.IPv4 for mDNS. Dec 15 14:59:10 volumio avahi-daemon[997]: Registering new address record for 192.168.1.115 on eth0.IPv4. Dec 15 14:59:10 volumio dhcpcd[922]: eth0: adding route to 192.168.1.0/24 Dec 15 14:59:10 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 15 14:59:10 volumio sh[899]: eth0: adding default route via 192.168.1.1 Dec 15 14:59:10 volumio sh[899]: forked to background, child pid 921 Dec 15 14:59:10 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 15 14:59:10 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 15 14:59:10 volumio dhcpcd[922]: eth0: adding default route via 192.168.1.1 Dec 15 14:59:10 volumio nmbd[1235]: [2025/12/15 14:59:10.794735, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Dec 15 14:59:10 volumio nmbd[1235]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.115 for name WORKGROUP<1d>. Dec 15 14:59:10 volumio nmbd[1235]: This response was from IP 192.168.1.153, reporting an IP address of 192.168.1.153. Dec 15 14:59:10 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 15 14:59:10 volumio systemd[1]: Started nmbd.service - Samba NMB Daemon. Dec 15 14:59:10 volumio welcome[1673]: Resolved ip:[1] 192.168.1.115 Dec 15 14:59:10 volumio systemd[1]: Starting winbind.service - Samba Winbind Daemon... Dec 15 14:59:10 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 15 14:59:10 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 15 14:59:10 volumio ifplugd(eth0)[1183]: client: ifup: interface eth0 already configured Dec 15 14:59:10 volumio sh[1707]: eth0=eth0 Dec 15 14:59:10 volumio winbindd[1703]: [2025/12/15 14:59:10.916868, 0] ../../source3/winbindd/winbindd.c:1440(main) Dec 15 14:59:10 volumio winbindd[1703]: winbindd version 4.17.8-Raspbian started. Dec 15 14:59:10 volumio winbindd[1703]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 15 14:59:10 volumio winbindd[1703]: [2025/12/15 14:59:10.921067, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Dec 15 14:59:10 volumio winbindd[1703]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 15 14:59:10 volumio systemd[1]: Started winbind.service - Samba Winbind Daemon. Dec 15 14:59:10 volumio systemd[1]: Starting smbd.service - Samba SMB Daemon... Dec 15 14:59:10 volumio ifplugd(eth0)[1183]: Program executed successfully. Dec 15 14:59:11 volumio smbd[1715]: [2025/12/15 14:59:11.056002, 0] ../../source3/smbd/server.c:1741(main) Dec 15 14:59:11 volumio smbd[1715]: smbd version 4.17.8-Raspbian started. Dec 15 14:59:11 volumio smbd[1715]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Dec 15 14:59:11 volumio systemd[1]: Started smbd.service - Samba SMB Daemon. Dec 15 14:59:11 volumio systemd[1]: Reached target multi-user.target - Multi-User System. Dec 15 14:59:11 volumio systemd[1]: Reached target graphical.target - Graphical Interface. Dec 15 14:59:11 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 15 14:59:11 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 15 14:59:11 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 15 14:59:11 volumio systemd[1]: Startup finished in 11.348s (kernel) + 13.687s (userspace) = 25.036s. Dec 15 14:59:11 volumio volumio[1317]: info: Discovery: this is already registered, 1400cf76-61cb-40c3-a26e-621f3ea73bdf Dec 15 14:59:11 volumio volumio[1317]: info: Discovery: Found device Volumio Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:11 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:11 volumio sudo[1736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:59:11 volumio sudo[1736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:11 volumio sudo[1738]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:59:11 volumio sudo[1738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:11 volumio sudo[1736]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:11 volumio sudo[1738]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:11 volumio volumio[1317]: verbose: New Socket.io Connection to 192.168.1.115 from 192.168.1.161 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:11 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 14:59:11 volumio volumio[1317]: info: Received Get System Info Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 14:59:11 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:11 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:11 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:11 volumio volumio[1317]: info: Listing playlists Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 15 14:59:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 14:59:12 volumio sudo[1742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=egn,password=1022,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.153/music /mnt/NAS/Truenas Dec 15 14:59:12 volumio sudo[1742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:12 volumio sudo[1744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.1.153:/music /mnt/NAS/Truenas Dec 15 14:59:12 volumio sudo[1744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:12 volumio kernel: CIFS: Attempting to mount //192.168.1.153/music Dec 15 14:59:12 volumio systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Dec 15 14:59:12 volumio systemd[1]: Starting rpc-statd.service - NFS status monitor for NFSv2/3 locking.... Dec 15 14:59:12 volumio rpc.statd[1762]: Version 2.6.2 starting Dec 15 14:59:12 volumio rpc.statd[1762]: Flags: TI-RPC Dec 15 14:59:12 volumio systemd[1]: Started rpc-statd.service - NFS status monitor for NFSv2/3 locking.. Dec 15 14:59:12 volumio systemd[1]: Reloading. Dec 15 14:59:12 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:12] [connect] Successful connection Dec 15 14:59:12 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:12 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:12 volumio volumio-remote-updater[1007]: [2025-12-15 14:59:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765785552 101 Dec 15 14:59:12 volumio volumio[1317]: 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: 3 Dec 15 14:59:12 volumio ntpd[1191]: IO: Listen normally on 3 eth0 192.168.1.115:123 Dec 15 14:59:12 volumio ntpd[1191]: IO: new interface(s) found: waking up resolver Dec 15 14:59:12 volumio ntpd[1191]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:12 volumio sudo[1742]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:12 volumio ntpd[1191]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Dec 15 14:59:12 volumio ntpd[1191]: DNS: Pool taking: 202.12.97.45 Dec 15 14:59:12 volumio ntpd[1191]: DNS: Pool taking: 202.29.58.130 Dec 15 14:59:12 volumio ntpd[1191]: DNS: Pool taking: 124.109.2.169 Dec 15 14:59:12 volumio ntpd[1191]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Dec 15 14:59:12 volumio sudo[1790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:59:12 volumio sudo[1790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:12 volumio sudo[1793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:59:12 volumio sudo[1793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:13 volumio systemd[1]: /lib/systemd/system/roonbridge.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:59:13 volumio systemd[1]: /lib/systemd/system/roonbridge.service:8: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:59:13 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:59:13 volumio sudo[1790]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:13 volumio sudo[1793]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:13 volumio mpd_monitor.sh[1795]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:59:13 volumio volumio[1317]: info: Successfully started MPD Monitor Dec 15 14:59:13 volumio volumio[1317]: info: Successfully started MPD Monitor Dec 15 14:59:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 15 14:59:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 14:59:13 volumio volumio[1317]: info: Received Get System Info Dec 15 14:59:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 14:59:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 14:59:13 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 14:59:13 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:13 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 14:59:13 volumio ntpd[1191]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:13 volumio ntpd[1191]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 202.28.117.7 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 147.50.17.138 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 171.103.24.86 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 240b:400f:8:3a07:400:115:974f:c952 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 2406:3100:1010:c03::149 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 2a0d:5600:21:25:0:2:0:5 Dec 15 14:59:13 volumio ntpd[1191]: DNS: Pool taking: 2001:c38:2000:180:d82a:1aff:fe38:f84b Dec 15 14:59:13 volumio ntpd[1191]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Dec 15 14:59:14 volumio dhcpcd[1052]: eth0: leased 192.168.1.115 for 86400 seconds Dec 15 14:59:14 volumio dhcpcd[1052]: eth0: adding route to 192.168.1.0/24 Dec 15 14:59:14 volumio dhcpcd[1052]: eth0: adding default route via 192.168.1.1 Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 15 14:59:14 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 15 14:59:14 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 15 14:59:14 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 15 14:59:14 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 15 14:59:14 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 15 14:59:14 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 15 14:59:14 volumio welcome[1821]: Resolved ip:[1] 192.168.1.115 Dec 15 14:59:14 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 15 14:59:14 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 14:59:14 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 14:59:14 volumio ntpd[1191]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:14 volumio ntpd[1191]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 15 14:59:14 volumio ntpd[1191]: DNS: Pool skipping: 202.28.117.7 Dec 15 14:59:14 volumio ntpd[1191]: DNS: Pool taking: 165.154.232.19 Dec 15 14:59:14 volumio ntpd[1191]: DNS: Pool skipping: 147.50.17.138 Dec 15 14:59:14 volumio ntpd[1191]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Dec 15 14:59:14 volumio volumio[1317]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:59:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 14:59:15 volumio volumio[1317]: info: Received Get System Info Dec 15 14:59:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 14:59:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 14:59:15 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 14:59:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:15 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 14:59:15 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Dec 15 14:59:15 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 14:59:15 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 14:59:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 15 14:59:15 volumio upmpdcli[1834]: Could not open config: /tmp/upmpdcli.conf Dec 15 14:59:15 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:59:15 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 14:59:15 volumio ntpd[1191]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 15 14:59:15 volumio ntpd[1191]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 15 14:59:15 volumio ntpd[1191]: DNS: Pool taking: 202.80.227.130 Dec 15 14:59:15 volumio ntpd[1191]: DNS: Pool taking: 202.28.33.225 Dec 15 14:59:15 volumio ntpd[1191]: DNS: Pool skipping: 171.103.24.86 Dec 15 14:59:15 volumio ntpd[1191]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Dec 15 14:59:16 volumio volumio[1317]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:59:16 volumio sudo[1851]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:59:16 volumio sudo[1851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:16 volumio sudo[1853]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:59:16 volumio sudo[1853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:16 volumio sudo[1851]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:16 volumio sudo[1853]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:16 volumio sudo[1857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:59:16 volumio sudo[1857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:17 volumio volumio[1317]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=3199c12e6eaea26afe2bb2e72801cb32" http://updates.volumio.org/downloader-v1/track-device Dec 15 14:59:17 volumio volumio[1317]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 15 14:59:17 volumio volumio[1317]: Dload Upload Total Spent Left Speed Dec 15 14:59:17 volumio volumio[1317]: [132B blob data] Dec 15 14:59:17 volumio volumio[1317]: retrying in 5 seconds, trial 0 Dec 15 14:59:17 volumio volumio[1317]: info: Volumio Calling Home Dec 15 14:59:18 volumio volumio[1317]: info: Volumio called home Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:59:18 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:59:42 volumio ntpd[1191]: CLOCK: time stepped by 23.545509 Dec 15 14:59:42 volumio ntpd[1191]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:59:42 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:42 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:42 volumio volumio[1317]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:59:42 volumio volumio[1317]: info: MyVolumio login type: Token Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:59:42 volumio volumio[1317]: info: Streaming services startup Dec 15 14:59:42 volumio volumio[1317]: info: Starting Streaming Daemon Dec 15 14:59:42 volumio sudo[1864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:59:42 volumio sudo[1864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:42 volumio volumio[1317]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:59:42 volumio sudo[1864]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:42 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 14:59:42 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Dec 15 14:59:42 volumio volumio[1317]: error: Cannot start Volumio Streaming Daemon Dec 15 14:59:42 volumio volumio[1317]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:59:42 volumio volumio[1317]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:59:42 volumio sudo[1871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount /mnt/NAS/Truenas Dec 15 14:59:42 volumio sudo[1871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:42 volumio systemd[1]: mnt-NAS-Truenas.mount: Deactivated successfully. Dec 15 14:59:42 volumio sudo[1871]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:42 volumio volumio[1317]: info: Share Truenas successfully unmounted Dec 15 14:59:43 volumio volumio[1317]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:59:43 volumio sudo[1744]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:43 volumio volumio[1317]: info: Cannot mount NAS Truenas at system boot, trial number 2 ,retrying in 5 seconds Dec 15 14:59:43 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 14:59:44 volumio volumio[1317]: info: MyVolumio token set successfully Dec 15 14:59:44 volumio volumio[1317]: info: MYVOLUMIO: Adding device Dec 15 14:59:44 volumio volumio[1317]: info: MYVOLUMIO: Evaluating Server Dec 15 14:59:44 volumio volumio[1317]: info: MyVolumio Plan changed: premium Dec 15 14:59:44 volumio volumio[1317]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 15 14:59:44 volumio volumio[1317]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:59:44 volumio volumio[1317]: info: Removing audio output: Dec 15 14:59:44 volumio volumio[1317]: info: MYVOLUMIO: Adding device Dec 15 14:59:44 volumio volumio[1317]: info: MYVOLUMIO: Evaluating Server Dec 15 14:59:44 volumio volumio[1317]: info: Remote config written successfully Dec 15 14:59:44 volumio volumio[1317]: info: Starting Tunnel 1 Dec 15 14:59:44 volumio volumio[1317]: info: Starting Tunnel Connection Checker Dec 15 14:59:44 volumio volumio[1317]: info: Completed starting MyVolumio Plugin Dec 15 14:59:44 volumio volumio[1317]: info: MYVolumio Device enabled Dec 15 14:59:44 volumio volumio[1317]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 15 14:59:44 volumio volumio[1317]: info: MyVolumio status changed Dec 15 14:59:44 volumio volumio[1317]: info: Streaming services startup Dec 15 14:59:44 volumio volumio[1317]: info: Starting Streaming Daemon Dec 15 14:59:44 volumio sudo[1921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:59:44 volumio sudo[1921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:44 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 15 14:59:44 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 15 14:59:44 volumio sudo[1921]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:44 volumio volumio[1317]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 15 14:59:44 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 15 14:59:45 volumio sudo[1926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 15 14:59:45 volumio sudo[1926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio sudo[1926]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio volumio[1317]: info: MRS: MultiRoom plugin initialized Dec 15 14:59:45 volumio volumio[1317]: info: MRS: STOPPING SNAPCLIENT Dec 15 14:59:45 volumio volumio[1317]: info: MRS: Snap server stop Dec 15 14:59:45 volumio sudo[1943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 15 14:59:45 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio volumio[1317]: info: MRS: STOPPING volumioStreaming Dec 15 14:59:45 volumio sudo[1946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 15 14:59:45 volumio sudo[1946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio sudo[1949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 15 14:59:45 volumio sudo[1949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 15 14:59:45 volumio sudo[1952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 15 14:59:45 volumio sudo[1952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio sudo[1952]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 15 14:59:45 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 15 14:59:45 volumio sudo[1946]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 15 14:59:45 volumio sudo[1949]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio volumio[1317]: info: Preparing to generate the ALSA configuration file Dec 15 14:59:45 volumio volumio[1317]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 15 14:59:45 volumio volumio[1317]: info: Reading ALSA contributions from plugins. Dec 15 14:59:45 volumio volumio[1317]: info: Setting Geolocation for MyVolumio to as1 Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:45 volumio volumio[1317]: info: MRS: Removed streaming files Dec 15 14:59:45 volumio volumio[1317]: info: MRS: volumioStreaming STOPPED Dec 15 14:59:45 volumio volumio[1317]: info: MRS: SNAPSERVER STOPPED Dec 15 14:59:45 volumio volumio[1317]: info: MRS: SNAPCLIENT STOPPED Dec 15 14:59:45 volumio volumio[1317]: error: Cannot start Volumio Streaming Daemon Dec 15 14:59:45 volumio volumio[1317]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:59:45 volumio volumio[1317]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 15 14:59:45 volumio volumio[1317]: info: Asound.conf file written Dec 15 14:59:45 volumio sudo[1958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 15 14:59:45 volumio sudo[1958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio sudo[1958]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio volumio[1317]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 15 14:59:45 volumio volumio[1317]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 15 14:59:45 volumio volumio[1317]: info: Output device has changed, restarting MPD Dec 15 14:59:45 volumio volumio[1317]: info: Output device has changed, restarting Shairport Sync Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:45 volumio sudo[1964]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:59:45 volumio sudo[1964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio sudo[1964]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio sudo[1966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:59:45 volumio sudo[1966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:45 volumio volumio[1317]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 14:59:45 volumio volumio[1317]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:45 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 15 14:59:45 volumio volumio[1317]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 15 14:59:45 volumio volumio[1317]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 15 14:59:45 volumio volumio[1317]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 15 14:59:45 volumio volumio[1317]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Dec 15 14:59:45 volumio volumio[1317]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 15 14:59:45 volumio volumio[1317]: info: MRS: Pushing multiroomSync output for this device Dec 15 14:59:45 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:45 volumio volumio[1317]: info: Adding audio output: Dec 15 14:59:45 volumio volumio[1317]: info: Adding audio output: Dec 15 14:59:45 volumio volumio[1317]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 15 14:59:45 volumio volumio[1317]: info: Adding METAVOLUMIO REST API Endpoints Dec 15 14:59:45 volumio volumio[1317]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 15 14:59:45 volumio volumio[1317]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 15 14:59:45 volumio volumio[1317]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 15 14:59:45 volumio volumio[1317]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 15 14:59:45 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 15 14:59:45 volumio volumio[1317]: info: Preparing CD Folders Dec 15 14:59:45 volumio volumio[1317]: info: Adding CD REST API Endpoints Dec 15 14:59:45 volumio volumio[1317]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 15 14:59:45 volumio volumio[1317]: info: Starting UDEV Watcher for CD Dec 15 14:59:45 volumio volumio[1317]: info: Detecting CD presence with UDEV Dec 15 14:59:45 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 15 14:59:45 volumio bluetoothd[998]: Path / reserved for Adv Monitor app :1.18 Dec 15 14:59:45 volumio bluetoothd[998]: Adv Monitor app :1.18 disconnected from D-Bus Dec 15 14:59:45 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:59:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:59:45 volumio systemd[1]: mpd.service: Consumed 1.286s CPU time. Dec 15 14:59:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:59:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:59:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:59:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:59:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:59:45 volumio sudo[1988]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:59:45 volumio sudo[1988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:59:45 volumio sudo[1988]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:45 volumio mpd[1990]: 2025-12-15T14:59:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:59:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:59:45 volumio sudo[1966]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumio[1317]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 15 14:59:50 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 15 14:59:50 volumio volumio[1317]: info: Adding inputs REST Endpoints Dec 15 14:59:50 volumio volumio[1317]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 15 14:59:50 volumio volumio[1317]: info: Scanning Audio Inputs Dec 15 14:59:50 volumio volumio[1317]: info: Checking against Known Cards name Dec 15 14:59:50 volumio volumio[1317]: info: Adding Server instance for streaming Dec 15 14:59:50 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 15 14:59:50 volumio volumio[1317]: error: Hi Res Audio Failed Login: Missing Login Data Dec 15 14:59:50 volumio volumio[1317]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 15 14:59:50 volumio volumio[1317]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 15 14:59:50 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 15 14:59:50 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 15 14:59:50 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 15 14:59:50 volumio volumio[1317]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 15 14:59:50 volumio volumio[1317]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 15 14:59:50 volumio sudo[2013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 15 14:59:50 volumio volumio[1317]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 15 14:59:50 volumio sudo[2013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio sudo[2020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 15 14:59:50 volumio sudo[2020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio volumio[1317]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 15 14:59:50 volumio volumio[1317]: info: Adding TIDAL REST API Endpoints Dec 15 14:59:50 volumio volumio[1317]: info: Stopping AccessToken refresher cron for QOBUZ Dec 15 14:59:50 volumio sudo[2020]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumio[1317]: info: AccessToken refresher cron started for QOBUZ Dec 15 14:59:50 volumio volumio[1317]: info: Adding QOBUZ REST API Endpoints Dec 15 14:59:50 volumio sudo[2022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 15 14:59:50 volumio sudo[2022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio sudo[2013]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumio[1317]: info: Updating MyVolumio device info Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: MRS: Getting audio outputs on start Dec 15 14:59:50 volumio volumio[1317]: info: MRS: Requesting all other devices output Dec 15 14:59:50 volumio sudo[2030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.1.153:/music /mnt/NAS/Truenas Dec 15 14:59:50 volumio sudo[2030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio volumio[1317]: info: Successfully Added MyVolumio device Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 14:59:50 volumio volumio[1317]: info: Setting Geolocation for MyVolumio to as1 Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: [1765785590415] Database update started Dec 15 14:59:50 volumio volumio[1317]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Dec 15 14:59:50 volumio volumio[1317]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 15 14:59:50 volumio volumio[1317]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Dec 15 14:59:50 volumio volumio[1317]: info: MPD Permissions set Dec 15 14:59:50 volumio sudo[2038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 15 14:59:50 volumio sudo[2038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 15 14:59:50 volumio sudo[2022]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:50 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Dec 15 14:59:50 volumio sudo[2038]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumio[1317]: error: updateQueue error: null Dec 15 14:59:50 volumio volumio[1317]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioStop Dec 15 14:59:50 volumio volumio[1317]: info: CoreStateMachine::stop Dec 15 14:59:50 volumio volumio[1317]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:59:50 volumio volumio[1317]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 15 14:59:50 volumio volumio[1317]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:59:50 volumio volumio[1317]: info: Starting Shairport Sync Dec 15 14:59:50 volumio sudo[2053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 14:59:50 volumio sudo[2053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio volumiobt[2054]: INFO [BTSTART] Ensuring Bluetooth directory exists... Dec 15 14:59:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 14:59:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 14:59:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 14:59:50 volumio systemd[1]: shairport-sync.service: Consumed 1.495s CPU time. Dec 15 14:59:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 14:59:50 volumio sudo[2053]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumio[1317]: info: Shairport-Sync Started Dec 15 14:59:50 volumio sudo[2056]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Dec 15 14:59:50 volumio sudo[2059]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:59:50 volumio sudo[2061]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:59:50 volumio sudo[2056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio sudo[2061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio sudo[2059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio sudo[2056]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio sudo[2061]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio sudo[2077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Dec 15 14:59:50 volumio sudo[2077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio sudo[2059]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio sudo[2077]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumiobt[2082]: INFO [BTSTART] Powering on Bluetooth if needed... Dec 15 14:59:50 volumio sudo[2074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 15 14:59:50 volumio sudo[2074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:59:50 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:59:50 volumio bluetoothd[998]: Adv Monitor app :1.21 disconnected from D-Bus Dec 15 14:59:50 volumio volumio[1317]: info: Executing endpoint qc_getconfig Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 15 14:59:50 volumio volumiobt[2088]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Dec 15 14:59:50 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.598 [2031.2031] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 15 14:59:50 volumio volumiobt[2090]: [176B blob data] Dec 15 14:59:50 volumio volumiobt[2090]: [157B blob data] Dec 15 14:59:50 volumio volumiobt[2090]: [157B blob data] Dec 15 14:59:50 volumio volumiobt[2090]: [157B blob data] Dec 15 14:59:50 volumio volumiobt[2090]: [113B blob data] Dec 15 14:59:50 volumio volumiobt[2090]: [bluetoothctl]> discoverable on Dec 15 14:59:50 volumio volumiobt[2090]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Dec 15 14:59:50 volumio volumiobt[2090]: [bluetoothctl]> pairable on Dec 15 14:59:50 volumio volumio[1317]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 15 14:59:50 volumio volumio[1317]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 15 14:59:50 volumio volumio[1317]: verbose: New Socket.io Connection to 192.168.1.115 from 192.168.1.161 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 14:59:50 volumio bluetoothd[998]: Adv Monitor app :1.22 disconnected from D-Bus Dec 15 14:59:50 volumio sudo[2074]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:50 volumio volumiobt[2090]: [bluetoothctl]> Dec 15 14:59:50 volumio volumiobt[2094]: INFO [BTSTART] Registering Bluetooth agent... Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 14:59:50 volumio volumio[1317]: info: Remote SSH Started Dec 15 14:59:50 volumio volumiobt[2095]: [NEW] Media /org/bluez/hci0 Dec 15 14:59:50 volumio volumiobt[2095]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Dec 15 14:59:50 volumio volumiobt[2095]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Dec 15 14:59:50 volumio volumiobt[2095]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Dec 15 14:59:50 volumio bluetoothd[998]: Adv Monitor app :1.23 disconnected from D-Bus Dec 15 14:59:50 volumio autossh[2093]: port set to 0, monitoring disabled Dec 15 14:59:50 volumio autossh[2093]: starting ssh (count 1) Dec 15 14:59:50 volumio autossh[2093]: ssh child pid is 2099 Dec 15 14:59:50 volumio volumiobt[2097]: No agent is registered Dec 15 14:59:50 volumio volumiobt[2097]: [NEW] Media /org/bluez/hci0 Dec 15 14:59:50 volumio volumiobt[2097]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Dec 15 14:59:50 volumio volumiobt[2097]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Dec 15 14:59:50 volumio volumiobt[2097]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Dec 15 14:59:50 volumio bluetoothd[998]: Path / reserved for Adv Monitor app :1.24 Dec 15 14:59:50 volumio bluetoothd[998]: Adv Monitor app :1.24 disconnected from D-Bus Dec 15 14:59:50 volumio volumiobt[2100]: INFO [BTSTART] Agent registered successfully. Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.677 [2031.2031] INFO VolumeManager: [0x16b9cb8]: Setting new playback volume: 75 Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.677 [2031.2031] INFO VolumeManager: [0x16b9cb8]: Setting new mute state: 0 Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.677 [2031.2031] INFO QobuzConnect: [0x16ba688]: Client initialized! Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.677 [2031.2031] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Dec 15 14:59:50 volumio volumiobt[2101]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.682 [2031.2031] INFO LocalConfigManager: [0x16b9598]: Starting Local Configuration server Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.682 [2031.2031] INFO SampleApp: Starting Local configuration server Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.682 [2031.2031] INFO SampleApp: Connected to UNIX socket client 0x16a4818 Dec 15 14:59:50 volumio volumio[1317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:50 volumio volumio[1317]: info: Retrieving Cloud Streaming UI Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 14:59:50 volumio volumio[1317]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 15 14:59:50 volumio volumio[1317]: info: Received Get System Info Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 14:59:50 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:50 volumio volumio[1317]: info: Listing playlists Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 14:59:50 volumio qobuz-connect[2031]: 20251215 14:59:50.749 [2031.2031] INFO SampleApp: Playback volume changed: 75 Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:50 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 14:59:50 volumio volumio[1317]: info: Getting Tidal Cloud Configuration Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:50 volumio volumio[1317]: info: Getting Qobuz Cloud Configuration Dec 15 14:59:50 volumio volumio[1317]: info: Asking plugin for UI Config Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:50 volumio volumio[1317]: info: Getting Spotify Cloud Configuration Dec 15 14:59:50 volumio volumio[1317]: info: Asking plugin for UI Config Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:50 volumio volumio[1317]: info: Saving Spotify Acccount Dec 15 14:59:50 volumio volumio[1317]: info: Got it Dec 15 14:59:50 volumio volumio[1317]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 15 14:59:50 volumio volumio[1317]: info: Got it Dec 15 14:59:50 volumio volumio[1317]: info: Got Tidal Cloud Configuration Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 14:59:50 volumio volumiossh-tunnel[2099]: Warning: Permanently added '[as1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 14:59:50 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 14:59:50 volumio volumio[1317]: info: Successfully Added MyVolumio device Dec 15 14:59:51 volumio volumio[1317]: info: Successfully Updated MyVolumio device Dec 15 14:59:51 volumio volumiobt[2102]: INFO:a2dp-agent:Connecting to system bus. Dec 15 14:59:51 volumio volumiobt[2102]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Dec 15 14:59:51 volumio volumiobt[2102]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Dec 15 14:59:51 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 15 14:59:51 volumio volumiobt[2102]: INFO:a2dp-agent:Registering agent. Dec 15 14:59:51 volumio volumiobt[2102]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Dec 15 14:59:51 volumio volumiobt[2102]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Dec 15 14:59:51 volumio volumio[1317]: info: Updating MyVolumio device info Dec 15 14:59:51 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:51 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:51 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:51 volumio volumio[1317]: info: Successfully Updated MyVolumio device Dec 15 14:59:51 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 15 14:59:52 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 15 14:59:52 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 14:59:52 volumio volumio[1317]: info: Received Get System Info Dec 15 14:59:52 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 14:59:52 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 14:59:52 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 14:59:52 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:52 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 14:59:53 volumio volumio[1317]: info: TidalConnect service stoped! Dec 15 14:59:53 volumio volumio[1317]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 15 14:59:53 volumio volumio[1317]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 15 14:59:53 volumio sudo[2124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 15 14:59:53 volumio sudo[2124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:53 volumio sudo[2128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:59:53 volumio sudo[2128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:59:53 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 15 14:59:53 volumio sudo[2124]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:53 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:59:53 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:59:53 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:59:53 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 14:59:53 volumio volumio[1317]: info: Received Get System Info Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 14:59:53 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 14:59:53 volumio mpd_monitor.sh[2132]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:59:53 volumio sudo[2128]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:53 volumio volumio[1317]: info: Successfully started MPD Monitor Dec 15 14:59:53 volumio volumio[1317]: info: Executing endpoint tc_getconfig Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 15 14:59:53 volumio vtcs[2130]: STARTING TidalConnect services, version: 1.5.2.56 Dec 15 14:59:53 volumio vtcs[2130]: STARTED TidalConnect services. Dec 15 14:59:53 volumio volumio[1317]: info: Executing endpoint tc_connect Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 15 14:59:53 volumio volumio[1317]: info: Connecting to TidalConnect Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::servicePushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:53 volumio volumio[1317]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 15 14:59:53 volumio volumio[1317]: verbose: CURRENT POSITION 0 Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::syncState stateService stop Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::syncState currentStatus stop Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: info: No code Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::servicePushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 14:59:53 volumio volumio[1317]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 15 14:59:53 volumio volumio[1317]: verbose: CURRENT POSITION 0 Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::syncState stateService stop Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::syncState currentStatus stop Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: info: No code Dec 15 14:59:53 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 14:59:53 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 14:59:53 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:53 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 14:59:53 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 14:59:53 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 14:59:53 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 14:59:54 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 15 14:59:54 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 14:59:54 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 14:59:54 volumio sudo[1857]: pam_unix(sudo:session): session closed for user root Dec 15 14:59:54 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 15 14:59:54 volumio volumio[1317]: info: Upmpdcli Daemon Started Dec 15 14:59:54 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 14:59:56 volumio volumio[1317]: info: TidalConnect service started! Dec 15 14:59:56 volumio volumio[1317]: [Metrics] CommandRouter: 27s 534.13ms Dec 15 14:59:56 volumio volumio[1317]: info: CoreCommandRouter::volumiosetStartupVolume Dec 15 14:59:56 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:59:56 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:59:56 volumio volumio[1317]: info: CoreCommandRouter::Close All Modals sent Dec 15 14:59:56 volumio volumio[1317]: info: CoreCommandRouter::Close All Modals sent Dec 15 14:59:56 volumio volumio[1317]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Dec 15 14:59:56 volumio volumio[1317]: ALSA lib ./src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Dec 15 14:59:56 volumio volumio[1317]: aplay: main:831: audio open error: Unknown error 524 Dec 15 14:59:57 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 15 14:59:57 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 15 14:59:57 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 15 14:59:57 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 14:59:57 volumio volumio[1317]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 15 14:59:57 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 14:59:58 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:00 volumio upmpdcli[2193]: writing RSA key Dec 15 15:00:00 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 15 15:00:01 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:00:01 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 15:00:01 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 15:00:01 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 15 15:00:01 volumio volumio-remote-updater[1007]: Test mode disabled Dec 15 15:00:01 volumio volumio-remote-updater[1007]: Alpha mode disabled Dec 15 15:00:01 volumio volumio-remote-updater[1007]: Alpha legacy test mode disabled Dec 15 15:00:01 volumio volumio[1317]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 15 15:00:01 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 15:00:02 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:03 volumio volumio[1317]: info: BOOT COMPLETED Dec 15 15:00:03 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , editShare Dec 15 15:00:03 volumio volumio[1317]: info: Share Truenas successfully unmounted Dec 15 15:00:03 volumio sudo[2212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=egn,password=1022,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.153//music /mnt/NAS/Truenas Dec 15 15:00:03 volumio sudo[2212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:00:03 volumio kernel: Malformed UNC in devname Dec 15 15:00:03 volumio kernel: CIFS: VFS: Malformed UNC in devname Dec 15 15:00:03 volumio sudo[2212]: pam_unix(sudo:session): session closed for user root Dec 15 15:00:03 volumio volumio[1317]: info: An error occurred mounting the new share. Rolling back configuration Dec 15 15:00:04 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 15:00:06 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:07 volumio sudo[2224]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 15:00:07 volumio sudo[2224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:00:07 volumio sudo[2224]: pam_unix(sudo:session): session closed for user root Dec 15 15:00:07 volumio sudo[2226]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 15:00:07 volumio sudo[2226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:00:07 volumio sudo[2226]: pam_unix(sudo:session): session closed for user root Dec 15 15:00:07 volumio volumio[1317]: verbose: New Socket.io Connection to 192.168.1.115 from 192.168.1.161 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:00:07 volumio volumio[1317]: info: Retrieving Cloud Streaming UI Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 15:00:07 volumio volumio[1317]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 15 15:00:07 volumio volumio[1317]: info: Received Get System Info Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:00:07 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:07 volumio volumio[1317]: info: Listing playlists Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 15:00:07 volumio volumio[1317]: info: Getting Tidal Cloud Configuration Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:00:07 volumio volumio[1317]: info: Getting Qobuz Cloud Configuration Dec 15 15:00:07 volumio volumio[1317]: info: Asking plugin for UI Config Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:00:07 volumio volumio[1317]: info: Getting Spotify Cloud Configuration Dec 15 15:00:07 volumio volumio[1317]: info: Asking plugin for UI Config Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:00:07 volumio volumio[1317]: info: Saving Spotify Acccount Dec 15 15:00:07 volumio volumio[1317]: info: Got it Dec 15 15:00:07 volumio volumio[1317]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 15 15:00:07 volumio volumio[1317]: info: Got Tidal Cloud Configuration Dec 15 15:00:07 volumio volumio[1317]: info: Got it Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:07 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 15:00:08 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 15 15:00:09 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 15 15:00:09 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 15:00:09 volumio volumio[1317]: info: Received Get System Info Dec 15 15:00:09 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:00:09 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:00:09 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 15:00:09 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:09 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:00:10 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 15 15:00:10 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Dec 15 15:00:10 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 15:00:10 volumio volumio[1317]: info: Received Get System Info Dec 15 15:00:10 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 15:00:10 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 15:00:10 volumio volumio[1317]: info: Discovery: Getting this device information Dec 15 15:00:10 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:10 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 15:00:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 15:00:11 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:13 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 15 15:00:13 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 15 15:00:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Dec 15 15:00:13 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Dec 15 15:00:15 volumio volumio[1317]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L truenas.local. -m SMB3_11 Dec 15 15:00:15 volumio volumio[1317]: info: Error browsing device truenas for shares: Command failed: smbclient --no-pass --debuglevel=0 -L truenas.local. -m SMB3_11 Dec 15 15:00:15 volumio volumio[1317]: info: MPD Database updated - AlbumList cache refreshed Dec 15 15:00:15 volumio volumio[1317]: info: Dec 15 15:00:15 volumio volumio[1317]: ---------------------------- MPD announces state update: database Dec 15 15:00:15 volumio volumio[1317]: verbose: ControllerMpd::sendMpdCommand status Dec 15 15:00:15 volumio volumio[1317]: info: Dec 15 15:00:15 volumio volumio[1317]: ---------------------------- MPD announces state update: update Dec 15 15:00:15 volumio volumio[1317]: info: ControllerMpd::getState Dec 15 15:00:15 volumio volumio[1317]: verbose: ControllerMpd::sendMpdCommand status Dec 15 15:00:15 volumio volumio[1317]: info: ControllerMpd::getState Dec 15 15:00:15 volumio volumio[1317]: verbose: ControllerMpd::sendMpdCommand status Dec 15 15:00:15 volumio volumio[1317]: info: sendMpdCommand status took 41 milliseconds Dec 15 15:00:15 volumio volumio[1317]: info: sendMpdCommand status took 41 milliseconds Dec 15 15:00:15 volumio volumio[1317]: info: sendMpdCommand status took 41 milliseconds Dec 15 15:00:15 volumio volumio[1317]: verbose: ControllerMpd::parseState Dec 15 15:00:15 volumio volumio[1317]: info: Command Router : Notfying DB Updatefalse Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::Close All Modals sent Dec 15 15:00:15 volumio volumio[1317]: verbose: ControllerMpd::parseState Dec 15 15:00:15 volumio volumio[1317]: verbose: ControllerMpd::parseState Dec 15 15:00:15 volumio volumio[1317]: info: ControllerMpd::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::servicePushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:15 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 15:00:15 volumio volumio[1317]: 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} Dec 15 15:00:15 volumio volumio[1317]: verbose: CURRENT POSITION 0 Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::syncState stateService stop Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::syncState currentStatus stop Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:15 volumio volumio[1317]: info: No code Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:15 volumio volumio[1317]: info: ControllerMpd::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::servicePushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:15 volumio volumio[1317]: info: CorePlayQueue::getTrack 0 Dec 15 15:00:15 volumio volumio[1317]: 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} Dec 15 15:00:15 volumio volumio[1317]: verbose: CURRENT POSITION 0 Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::syncState stateService stop Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::syncState currentStatus stop Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:15 volumio volumio[1317]: info: No code Dec 15 15:00:15 volumio volumio[1317]: info: CoreStateMachine::pushState Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioPushState Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:00:15 volumio volumio[1317]: info: MRS: Pushing multiroomSync output Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::volumioGetState Dec 15 15:00:15 volumio volumio[1317]: info: ------------------------------ 136ms Dec 15 15:00:15 volumio volumio[1317]: info: ------------------------------ 135ms Dec 15 15:00:15 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 15:00:15 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 15:00:15 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 15:00:15 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 15:00:15 volumio volumio[1317]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.XFgzNbCX9IcgT4UNLeudufB0LHz2.3199c12e6eaea26afe2bb2e72801cb32.state.status' Dec 15 15:00:15 volumio sudo[2030]: pam_unix(sudo:session): session closed for user root Dec 15 15:00:15 volumio volumio[1317]: info: Cannot mount NAS Truenas at system boot, trial number 3 ,retrying in 5 seconds Dec 15 15:00:15 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:17 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 15 15:00:19 volumio volumio[1317]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:00:20 volumio volumio[1317]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:00:20 volumio volumio[1317]: TypeError: Cannot read properties of undefined (reading 'replace') Dec 15 15:00:20 volumio volumio[1317]: at ControllerNetworkfs.mountShare (/volumio/app/plugins/system_controller/networkfs/index.js:202:28) Dec 15 15:00:20 volumio volumio[1317]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/networkfs/index.js:255:20) Dec 15 15:00:20 volumio volumio[1317]: at listOnTimeout (node:internal/timers:573:17) Dec 15 15:00:20 volumio volumio[1317]: at process.processTimers (node:internal/timers:514:7) Dec 15 15:00:20 volumio volumio[1317]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:00:20 volumio sudo[2316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:59' Dec 15 15:00:20 volumio sudo[2316]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"