-- Logs begin at Wed 2025-12-31 11:32:07 JST, end at Wed 2025-12-31 11:34:15 JST. -- Dec 31 11:33:00 rivoplus kernel: Firmware up: op_mode=0x0405, MAC=9c:b8:b4:96:00:72 Dec 31 11:33:00 rivoplus kernel: Driver: 1.579.77.41.10 (r) Firmware: wl0: Jan 19 2018 12:14:30 version 9.87.51.11.8 (a85e25e@shgit) (r) FWID 01-cb5aa0a5 CLM: 9.7.5 Dec 31 11:33:00 rivoplus kernel: dhd_txglom_enable: enable 1 Dec 31 11:33:00 rivoplus kernel: dhd_conf_set_txglom_params: txglom_mode=copy Dec 31 11:33:00 rivoplus kernel: dhd_conf_set_txglom_params: txglomsize=36, deferred_tx_len=0 Dec 31 11:33:00 rivoplus kernel: dhd_conf_set_txglom_params: txinrx_thres=128, dhd_txminmax=-1 Dec 31 11:33:00 rivoplus kernel: dhd_conf_set_txglom_params: tx_max_offset=0, txctl_tmo_fix=300 Dec 31 11:33:00 rivoplus kernel: dhd_conf_get_disable_proptx: fw_proptx=0, disable_proptx=1 Dec 31 11:33:00 rivoplus kernel: dhd_pno_init: Support Android Location Service Dec 31 11:33:00 rivoplus kernel: rtt_do_get_ioctl: failed to send getbuf proxd iovar (CMD ID : 1), status=-23 Dec 31 11:33:00 rivoplus kernel: dhd_rtt_init : FTM is not supported Dec 31 11:33:00 rivoplus kernel: dhd_preinit_ioctls: SensorHub diabled 0 Dec 31 11:33:00 rivoplus kernel: dhd_preinit_ioctls failed to set ShubHub disable Dec 31 11:33:00 rivoplus kernel: failed to set WNM capabilities Dec 31 11:33:00 rivoplus kernel: dhd_conf_set_country: set country ALL, revision 38 Dec 31 11:33:00 rivoplus kernel: CONFIG-ERROR) dhd_conf_set_bufiovar: country setting failed -2 Dec 31 11:33:00 rivoplus kernel: Country code: US (US/0) Dec 31 11:33:00 rivoplus kernel: CONFIG-ERROR) dhd_conf_set_intiovar: txbf setting failed -23 Dec 31 11:33:00 rivoplus kernel: wl_android_wifi_on: Success Dec 31 11:33:00 rivoplus kernel: dhd_open : the lock is released. Dec 31 11:33:00 rivoplus kernel: dhd_open: Exit ret=0 Dec 31 11:33:00 rivoplus avahi-daemon[2838]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Dec 31 11:33:00 rivoplus avahi-daemon[2838]: New relevant interface wlan0.IPv4 for mDNS. Dec 31 11:33:00 rivoplus avahi-daemon[2838]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Dec 31 11:33:00 rivoplus ntpd[3472]: Listen normally on 6 wlan0 192.168.211.1:123 Dec 31 11:33:00 rivoplus ntpd[3472]: new interface(s) found: waking up resolver Dec 31 11:33:00 rivoplus sudo[4563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 31 11:33:00 rivoplus sudo[4563]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 31 11:33:00 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:00.173Z level=INFO msg="BLE descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1d16ef8 Dec 31 11:33:00 rivoplus sudo[4575]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:00.176Z level=INFO msg="mDNS descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1d16ef8 Dec 31 11:33:00 rivoplus sudo[4561]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 31 11:33:00 rivoplus sudo[4583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Dec 31 11:33:00 rivoplus sudo[4561]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4563]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 31 11:33:00 rivoplus sudo[4580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 31 11:33:00 rivoplus sudo[4559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Dec 31 11:33:00 rivoplus sudo[4580]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4559]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 31 11:33:00 rivoplus sudo[4583]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4573]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4565]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4583]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:00.250Z level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.19:51112 Dec 31 11:33:00 rivoplus systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Dec 31 11:33:00 rivoplus hostapd[4600]: Configuration file: /etc/hostapd/hostapd.conf Dec 31 11:33:00 rivoplus kernel: wl_cfg80211_del_station: Disconnect STA : ff:ff:ff:ff:ff:ff scb_val.val 3 Dec 31 11:33:00 rivoplus qobuz-connect[4523]: 20251231 02:33:00.350 [4523.4605] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:00 rivoplus hostapd[4600]: Using interface wlan0 with hwaddr 9c:b8:b4:96:00:72 and ssid "Volumio-942FA" Dec 31 11:33:00 rivoplus kernel: wl_cfg80211_set_channel: netdev_ifidx(9), chan_type(1) target channel(4) Dec 31 11:33:00 rivoplus qobuz-connect[4523]: 20251231 02:33:00.359 [4523.4605] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:00 rivoplus kernel: CFG80211-ERROR) wl_bss_iovar_war : wl bss 3 Dec 31 11:33:00 rivoplus qobuz-connect[4523]: 20251231 02:33:00.367 [4523.4605] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:00 rivoplus qobuz-connect[4523]: 20251231 02:33:00.383 [4523.4605] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:00 rivoplus dhcpcd[3363]: wlan0: carrier acquired Dec 31 11:33:00 rivoplus kernel: wl_iw_event: Link UP with 9c:b8:b4:96:00:72 Dec 31 11:33:00 rivoplus kernel: wl_notify_connect_status_ap: ** AP/GO Link up event ** Dec 31 11:33:00 rivoplus hostapd[4600]: wlan0: interface state UNINITIALIZED->ENABLED Dec 31 11:33:00 rivoplus hostapd[4600]: wlan0: AP-ENABLED Dec 31 11:33:00 rivoplus systemd[1]: hostapd.service: Can't open PID file /run/hostapd.pid (yet?) after start: No such file or directory Dec 31 11:33:00 rivoplus sudo[4603]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Tokyo /etc/localtime Dec 31 11:33:00 rivoplus sudo[4603]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus dhcpcd[3363]: wlan0: IAID b4:96:00:72 Dec 31 11:33:00 rivoplus systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Dec 31 11:33:00 rivoplus sudo[4559]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4603]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus dhcpcd[3363]: wlan0: soliciting a DHCP lease Dec 31 11:33:00 rivoplus sudo[4617]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Dec 31 11:33:00 rivoplus sudo[4617]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus sudo[4580]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Dec 31 11:33:00 rivoplus sudo[4621]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus systemd[1]: wireless.service: Succeeded. Dec 31 11:33:00 rivoplus systemd[1]: Started Wireless Services. Dec 31 11:33:00 rivoplus sudo[4135]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4621]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 31 11:33:00 rivoplus systemd[1]: Started RAAT DAEMON. Dec 31 11:33:00 rivoplus sudo[4623]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Dec 31 11:33:00 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 31 11:33:00 rivoplus sudo[4629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Tokyo Dec 31 11:33:00 rivoplus systemd[1]: shairport-sync.service: Succeeded. Dec 31 11:33:00 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 31 11:33:00 rivoplus dhcpcd[3363]: wlan0: soliciting an IPv6 router Dec 31 11:33:00 rivoplus sudo[4629]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:00 rivoplus dnsmasq[4628]: dnsmasq: syntax check OK. Dec 31 11:33:00 rivoplus dbus-daemon[2860]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.53' (uid=0 pid=4637 comm="/usr/bin/timedatectl set-timezone Asia/Tokyo " label="kernel") Dec 31 11:33:00 rivoplus systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:00 rivoplus systemd[1]: mpd.service: Succeeded. Dec 31 11:33:00 rivoplus systemd[1]: Stopped Music Player Daemon. Dec 31 11:33:00 rivoplus sudo[4617]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4573]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus sudo[4575]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:00 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... Dec 31 11:33:00 rivoplus qobuz-connect[4523]: 20251231 11:33:00.963 [4523.4523] INFO SampleApp: Stopping Local configuration server Dec 31 11:33:00 rivoplus systemd[1]: Starting Time & Date Service... Dec 31 11:33:00 rivoplus qobuz-connect[4523]: 20251231 11:33:00.974 [4523.4523] INFO SampleApp: shat down connection on UNIX socket Dec 31 11:33:00 rivoplus systemd[1]: Starting Music Player Daemon... Dec 31 11:33:00 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 31 11:33:00 rivoplus sudo[4561]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:01 rivoplus systemd[1]: qobuz-connect.service: Succeeded. Dec 31 11:33:01 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. Dec 31 11:33:01 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. Dec 31 11:33:01 rivoplus sudo[4623]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:01 rivoplus dnsmasq[4654]: started, version 2.80 cachesize 150 Dec 31 11:33:01 rivoplus dnsmasq[4654]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Dec 31 11:33:01 rivoplus dnsmasq-dhcp[4654]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Dec 31 11:33:01 rivoplus dnsmasq[4654]: reading /etc/resolv.conf Dec 31 11:33:01 rivoplus dnsmasq[4654]: using nameserver 192.168.0.1#53 Dec 31 11:33:01 rivoplus dnsmasq[4654]: using nameserver 208.67.222.222#53 Dec 31 11:33:01 rivoplus dnsmasq[4654]: using nameserver 208.67.220.220#53 Dec 31 11:33:01 rivoplus dnsmasq[4654]: read /etc/hosts - 5 addresses Dec 31 11:33:01 rivoplus sudo[4647]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 31 11:33:01 rivoplus sudo[4647]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:01 rivoplus sudo[4647]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:01 rivoplus dbus-daemon[2860]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 31 11:33:01 rivoplus systemd[1]: Started Time & Date Service. Dec 31 11:33:01 rivoplus sudo[4629]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:01 rivoplus systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: Not Reporting Auto name since its the default one Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:01 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:01 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:01 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:01 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 31 11:33:01 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:01 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:01 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:01 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:01 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:01 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:01 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:01 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:01 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:01 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:01 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:01 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:01 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:01 rivoplus volumio[3203]: info: Shairport-Sync Started Dec 31 11:33:01 rivoplus volumio[3203]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 31 11:33:01 rivoplus volumio[3203]: info: QobuzConnect: setDeactiveState invoked Dec 31 11:33:01 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:01 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:01 rivoplus volumio[3203]: info: Raat Daemon started successfully Dec 31 11:33:01 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:02 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:02 rivoplus volumio[3203]: info: MPD Permissions set Dec 31 11:33:02 rivoplus volumio[3203]: info: RAAT: Requesting Headphone Status Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 31 11:33:02 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:02 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:02 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:02 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:02.240Z level=INFO msg="BLE descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1e08a40 Dec 31 11:33:02 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:02.243Z level=INFO msg="mDNS descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1e08a40 Dec 31 11:33:02 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:02.244Z level=INFO msg="BLE descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1e08a00 Dec 31 11:33:02 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:02.247Z level=INFO msg="mDNS descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1e08a00 Dec 31 11:33:02 rivoplus volumio[3203]: info: Executing endpoint restartRAATSocket Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Dec 31 11:33:02 rivoplus volumio[3203]: info: Executing endpoint qc_getconfig Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.347 [4651.4651] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.360 [4651.4651] INFO VolumeManager: [0xab439240]: Setting new playback volume: 75 Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.361 [4651.4651] INFO VolumeManager: [0xab439240]: Setting new mute state: 0 Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.361 [4651.4651] INFO QobuzConnect: [0xab439c10]: Client initialized! Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.361 [4651.4651] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.391 [4651.4651] INFO LocalConfigManager: [0xab438b20]: Starting Local Configuration server Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.391 [4651.4651] INFO SampleApp: Starting Local configuration server Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.392 [4651.4651] INFO SampleApp: Connected to UNIX socket client 0xab42eed8 Dec 31 11:33:02 rivoplus volumio[3203]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 31 11:33:02 rivoplus volumio[3203]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 31 11:33:02 rivoplus qobuz-connect[4651]: 20251231 11:33:02.497 [4651.4651] INFO SampleApp: Playback volume changed: 75 Dec 31 11:33:02 rivoplus volumio[3203]: info: Starting Shairport Sync Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Dec 31 11:33:02 rivoplus sudo[4696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 31 11:33:02 rivoplus sudo[4696]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:02 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 31 11:33:02 rivoplus systemd[1]: shairport-sync.service: Succeeded. Dec 31 11:33:02 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 31 11:33:02 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:02 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:02 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 31 11:33:02 rivoplus sudo[4696]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:02 rivoplus volumio[3203]: info: MCU Signalled Headphone Mode Disabled Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Dec 31 11:33:02 rivoplus volumio[3203]: info: Reporting Headphone State: false Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:02 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:02 rivoplus sudo[4702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Dec 31 11:33:02 rivoplus sudo[4702]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:02 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:02 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:02 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":0,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:02 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:02 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:02 rivoplus sudo[4702]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:02 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:02 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:02 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:02 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:02 rivoplus sudo[4705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Dec 31 11:33:02 rivoplus sudo[4705]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:02 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:02 rivoplus volumio[3203]: info: Shairport-Sync Started Dec 31 11:33:02 rivoplus volumio[3203]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:02 rivoplus volumio[3203]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:02 rivoplus systemd[1]: Stopping RAAT DAEMON... Dec 31 11:33:02 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:02 rivoplus systemd[1]: raat-daemon.service: Succeeded. Dec 31 11:33:02 rivoplus systemd[1]: Stopped RAAT DAEMON. Dec 31 11:33:02 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:03 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:03 rivoplus volumio[3203]: 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 31 11:33:03 rivoplus systemd[1]: Started RAAT DAEMON. Dec 31 11:33:03 rivoplus sudo[4705]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus sudo[4709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 31 11:33:03 rivoplus sudo[4709]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:03 rivoplus systemd[1]: Started Volumio Tidal Connect Service. Dec 31 11:33:03 rivoplus volumio[3203]: info: Raat Daemon started successfully Dec 31 11:33:03 rivoplus sudo[4709]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus volumio[3203]: info: Executing endpoint restartRAATSocket Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Dec 31 11:33:03 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:03 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:03 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:03.330Z level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=27.225973ms timeout=10s Dec 31 11:33:03 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:03.331Z level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=29.78364ms platform=PLATFORM_IOS version=4.251222.0 Dec 31 11:33:03 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:03.331Z level=INFO msg="updating device settings from app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=29.78364ms language=en timezone=Asia/Tokyo Dec 31 11:33:03 rivoplus volumio[3203]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 31 11:33:03 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:03.347Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=6.537682ms timeout=10s from=APP_PAGE_ROOT Dec 31 11:33:03 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:03 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:03 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Dec 31 11:33:03 rivoplus volumio[3203]: info: Loading i18n strings for locale en Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:03 rivoplus qobuz-connect[4651]: 20251231 11:33:03.454 [4651.4725] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:03 rivoplus qobuz-connect[4651]: 20251231 11:33:03.457 [4651.4725] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Dec 31 11:33:03 rivoplus volumio[3203]: info: Setting timezone to Asia/Tokyo Dec 31 11:33:03 rivoplus sudo[4728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Dec 31 11:33:03 rivoplus sudo[4728]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:03 rivoplus sudo[4728]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus sudo[4731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Tokyo /etc/localtime Dec 31 11:33:03 rivoplus sudo[4731]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:03 rivoplus sudo[4731]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus sudo[4735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Dec 31 11:33:03 rivoplus sudo[4735]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:03 rivoplus sudo[4735]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:03.819Z level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=1 Dec 31 11:33:03 rivoplus sudo[4738]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Tokyo Dec 31 11:33:03 rivoplus sudo[4738]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:03 rivoplus sudo[4738]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:03 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 31 11:33:03 rivoplus mpd[4662]: Dec 31 11:33 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 31 11:33:03 rivoplus sudo[4488]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:03 rivoplus systemd[1]: Started Music Player Daemon. Dec 31 11:33:03 rivoplus sudo[4565]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:04 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:04 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:04 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:04 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:04 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:04 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:04 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:04 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:04 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:04 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:04 rivoplus volumio[3203]: info: Fetching Streaming Services browse cache Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/2f68bb8d6a6bf3145d4ca8e886a20dcc.jpg","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1767148382906,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:04 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:04 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:04 rivoplus qobuz-connect[4651]: 20251231 11:33:04.234 [4651.4725] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:04 rivoplus qobuz-connect[4651]: 20251231 11:33:04.259 [4651.4725] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:04 rivoplus volumio[3203]: Updating browse sources language Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:33:04 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:04 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:04 rivoplus volumio[3203]: info: Executing endpoint tc_getconfig Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 31 11:33:04 rivoplus vtcs[4720]: STARTING TidalConnect services, version: 1.5.2.56 Dec 31 11:33:04 rivoplus vtcs[4720]: STARTED TidalConnect services. Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:04 rivoplus volumio[3203]: error: MPD error: The expression evaluated to a falsy value: Dec 31 11:33:04 rivoplus volumio[3203]: assert.ok(self.idling) Dec 31 11:33:04 rivoplus volumio[3203]: error: The expression evaluated to a falsy value: Dec 31 11:33:04 rivoplus volumio[3203]: assert.ok(self.idling) Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: error: updateQueue error: null Dec 31 11:33:04 rivoplus volumio[3203]: info: Executing endpoint tc_connect Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 31 11:33:04 rivoplus volumio[3203]: info: Connecting to TidalConnect Dec 31 11:33:04 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:04.465Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=-1.032109ms timeout=10s from=APP_PAGE_ROOT Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:04 rivoplus volumio[3203]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:04 rivoplus volumio[3203]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: 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 31 11:33:04 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService stop Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus volumio[3203]: info: No code Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus sudo[4775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus sudo[4775]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: 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 31 11:33:04 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService stop Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus volumio[3203]: info: No code Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:04 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:04 rivoplus sudo[4775]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:04 rivoplus volumio[3203]: info: Discovery: adding 8516dce9-f2ad-45a2-ab13-74aedbc01e76 Dec 31 11:33:04 rivoplus volumio[3203]: info: Discovery: Found device Rivoplus Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:04 rivoplus volumio[3203]: info: Discovery: this is already registered, 8516dce9-f2ad-45a2-ab13-74aedbc01e76 Dec 31 11:33:04 rivoplus volumio[3203]: info: Discovery: Found device Rivoplus Dec 31 11:33:04 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:04 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:05 rivoplus dhcpcd[3363]: wlan0: probing for an IPv4LL address Dec 31 11:33:05 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:05.552Z level=INFO msg="set device language" component=server type=REQUEST_TYPE_SET_DEVICE_LANGUAGE peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=270.974µs timeout=10s language=ja Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Dec 31 11:33:05 rivoplus volumio[3203]: info: Loading i18n strings for locale ja Dec 31 11:33:05 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:05.631Z level=INFO msg="set device timezone" component=server type=REQUEST_TYPE_SET_DEVICE_TIMEZONE peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=1.474933ms timeout=10s timezone=Asia/Tokyo Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Dec 31 11:33:05 rivoplus volumio[3203]: Updating browse sources language Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Dec 31 11:33:05 rivoplus volumio[3203]: info: Setting timezone to Asia/Tokyo Dec 31 11:33:05 rivoplus sudo[4798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Dec 31 11:33:05 rivoplus sudo[4798]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:05 rivoplus sudo[4798]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:05 rivoplus sudo[4801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Tokyo /etc/localtime Dec 31 11:33:05 rivoplus sudo[4801]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:05 rivoplus sudo[4801]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:05 rivoplus sudo[4804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Dec 31 11:33:05 rivoplus sudo[4804]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:05 rivoplus sudo[4804]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:05 rivoplus sudo[4807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Tokyo Dec 31 11:33:05 rivoplus sudo[4807]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:05 rivoplus sudo[4807]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:05 rivoplus volumio[3203]: info: RAAT: Requesting Headphone Status Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Dec 31 11:33:05 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 31 11:33:06 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:06.006Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=-579.359µs timeout=10s from=APP_PAGE_SETUP_V1_INTRO Dec 31 11:33:06 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:06 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:06 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:06 rivoplus volumio[3203]: info: MCU Signalled Headphone Mode Disabled Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Dec 31 11:33:06 rivoplus volumio[3203]: info: Reporting Headphone State: false Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:06 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:06 rivoplus volumio[3203]: info: Fetching Streaming Services browse cache Dec 31 11:33:06 rivoplus volumio[3203]: info: TidalConnect service started! Dec 31 11:33:06 rivoplus volumio[3203]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 6 Dec 31 11:33:06 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:06 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:06 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 31 11:33:06 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:06.834Z level=INFO msg="BLE descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x20a8038 Dec 31 11:33:06 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:06.836Z level=INFO msg="mDNS descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x20a8038 Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Dec 31 11:33:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Dec 31 11:33:07 rivoplus sudo[4820]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 31 11:33:07 rivoplus sudo[4820]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:07 rivoplus sudo[4820]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 31 11:33:07 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 31 11:33:08 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:08.633Z level=INFO msg="set device name" component=server type=REQUEST_TYPE_SET_DEVICE_NAME peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=5.087726ms timeout=10s name=Rivoplus Dec 31 11:33:08 rivoplus volumio[3203]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 31 11:33:08 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:08 rivoplus volumio[3203]: info: Starting MyVolumio Remote Streaming Endpoints Dec 31 11:33:08 rivoplus volumio[3203]: info: MyVolumio not started Dec 31 11:33:08 rivoplus volumio[3203]: info: Initializing device activation check Dec 31 11:33:08 rivoplus volumio[3203]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 31 11:33:08 rivoplus volumio[3203]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Dec 31 11:33:08 rivoplus sudo[4824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 31 11:33:08 rivoplus sudo[4824]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Dec 31 11:33:08 rivoplus volumio[3203]: info: TidalConnect service started! Dec 31 11:33:08 rivoplus sudo[4827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 31 11:33:08 rivoplus sudo[4827]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:08 rivoplus systemd[1]: Stopping MPD Monitor Service... Dec 31 11:33:08 rivoplus systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:08 rivoplus systemd[1]: mpd_monitor.service: Succeeded. Dec 31 11:33:08 rivoplus systemd[1]: Stopped MPD Monitor Service. Dec 31 11:33:08 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:08 rivoplus systemd[1]: Started MPD Monitor Service. Dec 31 11:33:08 rivoplus sudo[4824]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetVisibleSources Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Dec 31 11:33:08 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Dec 31 11:33:08 rivoplus systemd[1]: Stopping MPD Monitor Service... Dec 31 11:33:08 rivoplus systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:08 rivoplus systemd[1]: mpd_monitor.service: Succeeded. Dec 31 11:33:08 rivoplus systemd[1]: Stopped MPD Monitor Service. Dec 31 11:33:08 rivoplus systemd[1]: Started MPD Monitor Service. Dec 31 11:33:08 rivoplus sudo[4827]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:08 rivoplus mpd_monitor.sh[4831]: MPD Monitor Service: Starting MPD Monitor Service Dec 31 11:33:09 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:09 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Dec 31 11:33:09 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:09 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:09 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:09 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:09 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:09 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:09 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:09 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:09 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:09 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:09 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:09 rivoplus volumio[3203]: info: Successfully started MPD Monitor Dec 31 11:33:09 rivoplus volumio[3203]: info: Successfully started MPD Monitor Dec 31 11:33:09 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:09.169Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=-1.094732ms timeout=10s from=APP_PAGE_SETUP_V1_NAME Dec 31 11:33:09 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:09.199Z level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=357.268µs timeout=1m0s Dec 31 11:33:09 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:09 rivoplus dhcpcd[3363]: wlan0: using IPv4LL address 169.254.49.117 Dec 31 11:33:09 rivoplus avahi-daemon[2838]: Registering new address record for 169.254.49.117 on wlan0.IPv4. Dec 31 11:33:09 rivoplus dhcpcd[3363]: wlan0: adding route to 169.254.0.0/16 Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:10 rivoplus volumio[3203]: info: Retrieving Cloud Streaming UI Dec 31 11:33:10 rivoplus volumio[3203]: info: Getting Tidal Cloud Configuration Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:10 rivoplus volumio[3203]: info: Getting Qobuz Cloud Configuration Dec 31 11:33:10 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:10 rivoplus volumio[3203]: info: Getting Spotify Cloud Configuration Dec 31 11:33:10 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:10 rivoplus volumio[3203]: info: Saving Spotify Acccount Dec 31 11:33:10 rivoplus volumio[3203]: info: Got it Dec 31 11:33:10 rivoplus volumio[3203]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 31 11:33:10 rivoplus volumio[3203]: info: Got Tidal Cloud Configuration Dec 31 11:33:10 rivoplus volumio[3203]: info: Got it Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:10 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:10 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:10 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 31 11:33:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 31 11:33:10 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:10.431Z level=INFO msg="BLE descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1c263f0 Dec 31 11:33:10 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:10.435Z level=INFO msg="mDNS descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1c263f0 Dec 31 11:33:11 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:11.078Z level=WARN msg="received acknowledgment for unexpected write index" component=conn/ble data=0100 addr=1 Dec 31 11:33:11 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Dec 31 11:33:11 rivoplus volumio[3203]: info: Loading i18n strings for locale en Dec 31 11:33:11 rivoplus volumio[3203]: Updating browse sources language Dec 31 11:33:11 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:33:11 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Dec 31 11:33:11 rivoplus volumio[3203]: info: Setting timezone to Asia/Tokyo Dec 31 11:33:11 rivoplus sudo[4913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Dec 31 11:33:11 rivoplus sudo[4913]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:11 rivoplus sudo[4913]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:11 rivoplus ntpd[3472]: Listen normally on 7 wlan0 169.254.49.117:123 Dec 31 11:33:11 rivoplus ntpd[3472]: new interface(s) found: waking up resolver Dec 31 11:33:11 rivoplus sudo[4916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Tokyo /etc/localtime Dec 31 11:33:11 rivoplus sudo[4916]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:11 rivoplus sudo[4916]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:11 rivoplus sudo[4919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Dec 31 11:33:11 rivoplus sudo[4919]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:11 rivoplus sudo[4919]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:11 rivoplus sudo[4922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Tokyo Dec 31 11:33:11 rivoplus sudo[4922]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:11 rivoplus sudo[4922]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:11 rivoplus volumio[3203]: info: Fetching Streaming Services browse cache Dec 31 11:33:11 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Dec 31 11:33:12 rivoplus volumio[3203]: info: Refreshing Cached IP Addresses Dec 31 11:33:12 rivoplus sudo[4925]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Dec 31 11:33:12 rivoplus sudo[4925]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:12 rivoplus sudo[4928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 31 11:33:12 rivoplus sudo[4928]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:12 rivoplus sudo[4925]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:12 rivoplus volumio[3203]: error: Upnp client error: Error: This socket has been ended by the other party Dec 31 11:33:12 rivoplus sudo[4928]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:12 rivoplus sudo[4931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 31 11:33:12 rivoplus sudo[4931]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:12 rivoplus sudo[4931]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:12 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:12 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:12 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 31 11:33:12 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 31 11:33:12 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:12.851Z level=INFO msg="BLE descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1e08278 Dec 31 11:33:12 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:12.854Z level=INFO msg="mDNS descriptor updated" deviceId=942fa3d668849ba819d79b7c26078e22 deviceName=Rivoplus deviceModel=0x1e08278 Dec 31 11:33:13 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:13.779Z level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s Dec 31 11:33:14 rivoplus volumio[4127]: ..............................................................................................................................................................................................++++ Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.307Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=527.445792ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.419Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://www.googleapis.com duration=638.619125ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.449Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=http://pushupdates.volumio.org duration=665.493334ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.469Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://securetoken.googleapis.com duration=689.092334ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.489Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=710.099042ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.595Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=http://plugins.volumio.org duration=813.843834ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.634Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=854.3945ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.639Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=858.229125ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.704Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://functions.volumio.cloud duration=924.896125ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.706Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://functions.volumio.cloud duration=923.728626ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.710Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://database.volumio.cloud duration=927.436375ms Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.855Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=http://cddb.volumio.org duration=1.073058709s Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.860Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=32.086978ms timeout=10s endpoint=https://google.com duration=1.080831375s Dec 31 11:33:14 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:14.870Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=529.187µs timeout=10s from=APP_PAGE_SETUP_V1_INTERNET Dec 31 11:33:14 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:14 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:14 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:14 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:14 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:14 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:14 rivoplus volumio[4127]: .........++++ Dec 31 11:33:14 rivoplus volumio[4127]: e is 65537 (0x010001) Dec 31 11:33:15 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:15 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:16 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:16.882Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=1.547688ms timeout=10s from=APP_PAGE_SETUP_V1_UPDATE Dec 31 11:33:16 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:17 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 31 11:33:17 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:17 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 31 11:33:17 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:17 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:17 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 31 11:33:18 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:18 rivoplus volumio[3203]: error: MyVolumio Plugin failed to start in a timely fashion Dec 31 11:33:18 rivoplus volumio[3203]: [Metrics] CommandRouter: 57s 110.08ms Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::volumiosetStartupVolume Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::Close All Modals sent Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::Close All Modals sent Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Retrieving Cloud Streaming UI Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Retrieving Cloud Streaming UI Dec 31 11:33:18 rivoplus volumio[3203]: info: Getting Tidal Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Getting Qobuz Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Getting Spotify Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Saving Spotify Acccount Dec 31 11:33:18 rivoplus volumio[3203]: info: Got it Dec 31 11:33:18 rivoplus volumio[3203]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 31 11:33:18 rivoplus volumio[3203]: info: Getting Tidal Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Getting Qobuz Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Getting Spotify Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Saving Spotify Acccount Dec 31 11:33:18 rivoplus volumio[3203]: info: Got it Dec 31 11:33:18 rivoplus volumio[3203]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 31 11:33:18 rivoplus volumio[3203]: info: Got Tidal Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: Got it Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:18 rivoplus volumio[3203]: info: Got Tidal Cloud Configuration Dec 31 11:33:18 rivoplus volumio[3203]: info: Got it Dec 31 11:33:18 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:19 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 31 11:33:19 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:19 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:19 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:19 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 31 11:33:19 rivoplus volumio[3203]: info: Version has changed, forcing UI Reload Dec 31 11:33:19 rivoplus volumio[3203]: info: CoreCommandRouter::Reload Ui Dec 31 11:33:20 rivoplus volumio[3203]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 6 Dec 31 11:33:21 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:21.070Z level=INFO msg="login user" component=server type=REQUEST_TYPE_LOGIN_USER peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=337.899µs timeout=1m0s token=eyJhbGciOiJSUzI1****S4k4pS7TNRcp3xrA Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetVisibleSources Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Dec 31 11:33:21 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:21 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Dec 31 11:33:21 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:21 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:21 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:21 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:21 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:21 rivoplus volumio[3203]: info: Retrieving Cloud Streaming UI Dec 31 11:33:21 rivoplus volumio[3203]: info: Getting Tidal Cloud Configuration Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:21 rivoplus volumio[3203]: info: Getting Qobuz Cloud Configuration Dec 31 11:33:21 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:21 rivoplus volumio[3203]: info: Getting Spotify Cloud Configuration Dec 31 11:33:21 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:21 rivoplus volumio[3203]: info: Saving Spotify Acccount Dec 31 11:33:21 rivoplus volumio[3203]: info: Got it Dec 31 11:33:21 rivoplus volumio[3203]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 31 11:33:21 rivoplus volumio[3203]: info: Got Tidal Cloud Configuration Dec 31 11:33:21 rivoplus volumio[3203]: info: Got it Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:21 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:21.652Z level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=NfVgmabLiPfWWvBjnKkbQrI2F702 tokenExpiry=2025-12-31T03:33:21.652Z Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 31 11:33:21 rivoplus volumio[3203]: info: MyVolumio login type: Token Dec 31 11:33:21 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:21 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:22 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:22 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:22.091Z level=WARN msg="logged user ID does not match expected user ID" component=server type=REQUEST_TYPE_LOGIN_USER peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=337.899µs timeout=1m0s expected=NfVgmabLiPfWWvBjnKkbQrI2F702 actual= Dec 31 11:33:22 rivoplus sudo[4985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 31 11:33:22 rivoplus sudo[4985]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:22 rivoplus sudo[4985]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:22 rivoplus sudo[4987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 31 11:33:22 rivoplus sudo[4987]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:22 rivoplus sudo[4987]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:22 rivoplus sudo[4993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 31 11:33:22 rivoplus sudo[4993]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:22 rivoplus sudo[4993]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:22 rivoplus volumio[3203]: info: Upmpdcli Daemon Started Dec 31 11:33:22 rivoplus volumio[3203]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 31 11:33:22 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:23 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:33:23 rivoplus volumio[3203]: info: MyVolumio token set successfully Dec 31 11:33:23 rivoplus volumio[3203]: info: MYVOLUMIO: Adding device Dec 31 11:33:23 rivoplus volumio[3203]: info: MYVOLUMIO: Evaluating Server Dec 31 11:33:23 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Dec 31 11:33:23 rivoplus volumio[3203]: info: Loading i18n strings for locale en Dec 31 11:33:23 rivoplus volumio[3203]: Updating browse sources language Dec 31 11:33:23 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:33:23 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Dec 31 11:33:23 rivoplus volumio[3203]: info: Setting timezone to Asia/Tokyo Dec 31 11:33:23 rivoplus sudo[4998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Dec 31 11:33:23 rivoplus sudo[4998]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:23 rivoplus sudo[4998]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:23 rivoplus sudo[5001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Tokyo /etc/localtime Dec 31 11:33:23 rivoplus sudo[5001]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:23 rivoplus sudo[5001]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:23 rivoplus sudo[5005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Dec 31 11:33:23 rivoplus sudo[5005]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:23 rivoplus sudo[5005]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:23 rivoplus sudo[5008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Tokyo Dec 31 11:33:23 rivoplus sudo[5008]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:23 rivoplus sudo[5008]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:23 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 31 11:33:24 rivoplus volumio[3203]: info: MyVolumio Plan changed: premium Dec 31 11:33:24 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 31 11:33:24 rivoplus volumio[3203]: info: Removing browser output: myVolumio user plan is not superstar Dec 31 11:33:24 rivoplus volumio[3203]: info: Removing audio output: Dec 31 11:33:24 rivoplus volumio[3203]: info: MYVOLUMIO: Adding device Dec 31 11:33:24 rivoplus volumio[3203]: info: MYVOLUMIO: Evaluating Server Dec 31 11:33:24 rivoplus volumio[3203]: info: Fetching Streaming Services browse cache Dec 31 11:33:24 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:24 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:24.525Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=-629.308µs timeout=10s from=APP_PAGE_SETUP_V1_LOGIN_OPTIONS Dec 31 11:33:24 rivoplus volumio[3203]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 31 11:33:24 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 31 11:33:24 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:24 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:24 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:24 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:24 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:24 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:24 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:24 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:24 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:24 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:24 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:24 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:24 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:24 rivoplus volumio[3203]: info: Remote config written successfully Dec 31 11:33:24 rivoplus volumio[3203]: info: Starting Tunnel 1 Dec 31 11:33:24 rivoplus volumio[3203]: info: Starting Tunnel Connection Checker Dec 31 11:33:25 rivoplus volumio[3203]: info: Setting Geolocation for MyVolumio to as1 Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:25 rivoplus volumio[3203]: info: MYVolumio Device enabled Dec 31 11:33:25 rivoplus volumio[3203]: info: MyVolumio status changed Dec 31 11:33:25 rivoplus volumio[3203]: info: Streaming services startup Dec 31 11:33:25 rivoplus volumio[3203]: info: Starting Streaming Daemon Dec 31 11:33:25 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 31 11:33:25 rivoplus sudo[5064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 31 11:33:25 rivoplus sudo[5064]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:25 rivoplus sudo[5064]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:25 rivoplus volumio[3203]: error: [MyVolumio PluginManager] Could not read cache file: ENOENT: no such file or directory, open '/data/myvolumio/cache.data' Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:25 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:25 rivoplus volumio[3203]: error: Cannot start Volumio Streaming Daemon Dec 31 11:33:25 rivoplus volumio[3203]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 31 11:33:25 rivoplus volumio[3203]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 31 11:33:25 rivoplus volumio[3203]: info: BOOT COMPLETED Dec 31 11:33:25 rivoplus volumio[3203]: info: Setting Geolocation for MyVolumio to as1 Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:25 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:25 rivoplus volumio[3203]: info: Successfully Added MyVolumio device Dec 31 11:33:26 rivoplus volumio[3203]: info: Successfully Added MyVolumio device Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin audio_interface/bluetooth is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin audio_interface/multiroom is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin miscellanea/metavolumio is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin miscellanea/manifestui is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/cd_controller is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/smart_inputs is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/hi_res_audio is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/tidal is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/qobuz is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/tidalconnect is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: [MyVolumio PluginManager] Plugin music_service/qobuzconnect is enabled for this plan, but could not be found on the local filesystem! Dec 31 11:33:26 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 31 11:33:26 rivoplus volumio[3203]: info: Updating MyVolumio device info Dec 31 11:33:26 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:26 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:26 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:26 rivoplus volumio[3203]: info: Updating MyVolumio device info Dec 31 11:33:26 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:26 rivoplus volumio[3203]: info: Successfully Updated MyVolumio device Dec 31 11:33:26 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:27 rivoplus volumio[3203]: info: Successfully Updated MyVolumio device Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:27 rivoplus volumio[3203]: info: Not Reporting Auto name since its the default one Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Dec 31 11:33:27 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:27 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:27 rivoplus sudo[5090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Dec 31 11:33:27 rivoplus sudo[5090]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:27 rivoplus sudo[5090]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:27 rivoplus sudo[5092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Dec 31 11:33:27 rivoplus sudo[5092]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:27 rivoplus systemd[1]: Stopping RAAT DAEMON... Dec 31 11:33:27 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:27 rivoplus systemd[1]: raat-daemon.service: Succeeded. Dec 31 11:33:27 rivoplus systemd[1]: Stopped RAAT DAEMON. Dec 31 11:33:27 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:27 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:27 rivoplus sudo[5092]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:27 rivoplus volumio[3203]: info: Raat Daemon started successfully Dec 31 11:33:27 rivoplus systemd[1]: Started RAAT DAEMON. Dec 31 11:33:27 rivoplus volumio[3203]: info: Executing endpoint restartRAATSocket Dec 31 11:33:27 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Dec 31 11:33:27 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:27 rivoplus volumio[3203]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/2f68bb8d6a6bf3145d4ca8e886a20dcc.jpg","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1767148382906,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:28 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:28 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/2f68bb8d6a6bf3145d4ca8e886a20dcc.jpg","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1767148382906,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:28 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:28 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:28 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:28 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetBrowseSources Dec 31 11:33:28 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 31 11:33:29 rivoplus sudo[5122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 31 11:33:29 rivoplus sudo[5122]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:29 rivoplus systemd[1]: Started MyVolumio SSH Tunnel. Dec 31 11:33:29 rivoplus sudo[5122]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:29 rivoplus volumio[3203]: info: Remote SSH Started Dec 31 11:33:30 rivoplus autossh[5125]: port set to 0, monitoring disabled Dec 31 11:33:30 rivoplus autossh[5125]: starting ssh (count 1) Dec 31 11:33:30 rivoplus autossh[5125]: ssh child pid is 5128 Dec 31 11:33:30 rivoplus volumio[3203]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:30 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:30 rivoplus volumio[3203]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.NfVgmabLiPfWWvBjnKkbQrI2F702.942fa3d668849ba819d79b7c26078e22.state.mute' Dec 31 11:33:30 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:30.384Z level=INFO msg="set audio output" component=server type=REQUEST_TYPE_SET_AUDIO_OUTPUT peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=5.232778ms timeout=10s id=5 Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Dec 31 11:33:30 rivoplus volumiossh-tunnel[5124]: Warning: Permanently added '[as1.myvolumio.org]:2222,[128.199.166.162]:2222' (RSA) to the list of known hosts. Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 31 11:33:30 rivoplus volumio[3203]: info: Preparing to save Alsa Options, stopping services first Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:30 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPause Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreStateMachine::pause Dec 31 11:33:30 rivoplus volumio[3203]: info: Saving Audio Output to: {"i2s":false,"i2sid":{"value":"","label":""},"output_device":{"value":"5","label":"S/PDIF + AES/EBU + I2S"},"disallowPush":true} Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: info: Setting mixer PCM for card S/PDIF + AES/EBU + I2S Dec 31 11:33:30 rivoplus volumio[3203]: info: QobuzConnect: setDeactiveState invoked Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:30 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:30 rivoplus volumio[3203]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Dec 31 11:33:30 rivoplus vtcs[4720]: [2025-12-31 11:33:30.681] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 31 11:33:30 rivoplus vtcs[4720]: [2025-12-31 11:33:30.684] [tisoc] [error] [SpkconServer.cpp:380] recv error. client fd=8 errorno=104 error=Connection reset by peer Dec 31 11:33:30 rivoplus vtcs[4720]: [2025-12-31 11:33:30.684] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 31 11:33:30 rivoplus sudo[5138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 31 11:33:30 rivoplus sudo[5138]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:30 rivoplus systemd[1]: Stopping Volumio Tidal Connect Service... Dec 31 11:33:30 rivoplus systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:30 rivoplus systemd[1]: vtcs.service: Succeeded. Dec 31 11:33:30 rivoplus systemd[1]: Stopped Volumio Tidal Connect Service. Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 31 11:33:30 rivoplus sudo[5138]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:30 rivoplus volumio[3203]: info: Updating Volume Controller Parameters: Device: 5 Name: S/PDIF + AES/EBU + I2S Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 31 11:33:30 rivoplus volumio[3203]: info: Disabling external Volume Control Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:30 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:30 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:30 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:30 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:30 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:30 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:31 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:31 rivoplus volumio[3203]: info: Preparing to generate the ALSA configuration file Dec 31 11:33:31 rivoplus sudo[5153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 31 11:33:31 rivoplus sudo[5153]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:31 rivoplus sudo[5153]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:31 rivoplus volumio[3203]: info: RAAT: Requesting Headphone Status Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Dec 31 11:33:31 rivoplus sudo[5160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 31 11:33:31 rivoplus sudo[5160]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:31 rivoplus sudo[5160]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: Not Reporting Auto name since its the default one Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 31 11:33:31 rivoplus sudo[5166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 31 11:33:31 rivoplus sudo[5166]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:31 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... Dec 31 11:33:31 rivoplus qobuz-connect[4651]: 20251231 11:33:31.315 [4651.4651] INFO SampleApp: Stopping Local configuration server Dec 31 11:33:31 rivoplus qobuz-connect[4651]: 20251231 11:33:31.325 [4651.4651] INFO SampleApp: shat down connection on UNIX socket Dec 31 11:33:31 rivoplus systemd[1]: qobuz-connect.service: Succeeded. Dec 31 11:33:31 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. Dec 31 11:33:31 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:31 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. Dec 31 11:33:31 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:31 rivoplus sudo[5166]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:31 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:31 rivoplus volumio[3203]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 31 11:33:31 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus volumio[3203]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 31 11:33:31 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:31 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:31 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:31 rivoplus volumio[3203]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 31 11:33:31 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:31.535Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=-687.596µs timeout=10s from=APP_PAGE_SETUP_V1_AUDIO_OUTPUTS Dec 31 11:33:31 rivoplus volumio[3203]: info: Reading ALSA contributions from plugins. Dec 31 11:33:31 rivoplus volumio[3203]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:31 rivoplus volumio[3203]: info: MCU Signalled Headphone Mode Disabled Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Dec 31 11:33:31 rivoplus volumio[3203]: info: Reporting Headphone State: false Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:31 rivoplus volumio[3203]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 31 11:33:31 rivoplus volumio[3203]: info: QobuzConnect: setDeactiveState invoked Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:31 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:33:31 rivoplus volumio[3203]: info: Executing endpoint qc_getconfig Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.681 [5170.5170] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.687 [5170.5170] INFO VolumeManager: [0xab133240]: Setting new playback volume: 75 Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.688 [5170.5170] INFO VolumeManager: [0xab133240]: Setting new mute state: 0 Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.689 [5170.5170] INFO QobuzConnect: [0xab133c10]: Client initialized! Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.689 [5170.5170] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp Dec 31 11:33:31 rivoplus volumio[3203]: info: VolumeController:: Volume=undefined Mute =false Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:31 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:31 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:31 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:31 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.706 [5170.5170] INFO LocalConfigManager: [0xab132b20]: Starting Local Configuration server Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.706 [5170.5170] INFO SampleApp: Starting Local configuration server Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.707 [5170.5170] INFO SampleApp: Connected to UNIX socket client 0xab128ed8 Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Dec 31 11:33:31 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus qobuz-connect[5170]: 20251231 11:33:31.830 [5170.5170] INFO SampleApp: Playback volume changed: 75 Dec 31 11:33:31 rivoplus sudo[5187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Dec 31 11:33:31 rivoplus sudo[5187]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:31 rivoplus sudo[5187]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:31 rivoplus sudo[5191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Dec 31 11:33:31 rivoplus sudo[5191]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:31 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:31 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:31 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 31 11:33:31 rivoplus systemd[1]: Stopping RAAT DAEMON... Dec 31 11:33:31 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:31 rivoplus systemd[1]: raat-daemon.service: Succeeded. Dec 31 11:33:31 rivoplus systemd[1]: Stopped RAAT DAEMON. Dec 31 11:33:31 rivoplus systemd[1]: Started RAAT DAEMON. Dec 31 11:33:31 rivoplus sudo[5191]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:32 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:32 rivoplus volumio[3203]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 31 11:33:32 rivoplus volumio[3203]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 31 11:33:32 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:32 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:32 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:32 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:32 rivoplus volumio[3203]: info: Raat Daemon started successfully Dec 31 11:33:32 rivoplus volumio[3203]: info: Executing endpoint restartRAATSocket Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:32 rivoplus volumio[3203]: info: Asound.conf file unchanged, so no further update is needed Dec 31 11:33:32 rivoplus volumio[3203]: info: Output device has changed, restarting MPD Dec 31 11:33:32 rivoplus volumio[3203]: info: Output device has changed, restarting Shairport Sync Dec 31 11:33:32 rivoplus sudo[5208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 31 11:33:32 rivoplus sudo[5208]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:32 rivoplus sudo[5208]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus sudo[5210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 31 11:33:32 rivoplus sudo[5210]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus systemd[1]: Stopping Music Player Daemon... Dec 31 11:33:32 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:32 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:32 rivoplus volumio[3203]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 31 11:33:32 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:32 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:32 rivoplus volumio[3203]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus systemd[1]: mpd.service: Succeeded. Dec 31 11:33:32 rivoplus systemd[1]: Stopped Music Player Daemon. Dec 31 11:33:32 rivoplus systemd[1]: Starting Music Player Daemon... Dec 31 11:33:32 rivoplus volumio[3203]: info: QobuzConnect: setDeactiveState invoked Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:32 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:32 rivoplus volumio[3203]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus sudo[5221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 31 11:33:32 rivoplus sudo[5221]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus sudo[5221]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus sudo[5225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 31 11:33:32 rivoplus sudo[5225]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus sudo[5218]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 31 11:33:32 rivoplus sudo[5218]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus sudo[5225]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus sudo[5218]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus sudo[5235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 31 11:33:32 rivoplus sudo[5235]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:32 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:32 rivoplus sudo[5235]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus volumio[3203]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 31 11:33:32 rivoplus volumio[3203]: info: MPD Permissions set Dec 31 11:33:32 rivoplus sudo[5238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 31 11:33:32 rivoplus sudo[5238]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... Dec 31 11:33:32 rivoplus qobuz-connect[5170]: 20251231 11:33:32.668 [5170.5170] INFO SampleApp: Stopping Local configuration server Dec 31 11:33:32 rivoplus qobuz-connect[5170]: 20251231 11:33:32.679 [5170.5170] INFO SampleApp: shat down connection on UNIX socket Dec 31 11:33:32 rivoplus systemd[1]: qobuz-connect.service: Succeeded. Dec 31 11:33:32 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 31 11:33:32 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. Dec 31 11:33:32 rivoplus sudo[5238]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:32 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:32 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:32 rivoplus volumio[3203]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 31 11:33:32 rivoplus volumio[3203]: info: QobuzConnect: setDeactiveState invoked Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:32 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:32 rivoplus volumio[3203]: info: Starting Shairport Sync Dec 31 11:33:32 rivoplus volumio[3203]: info: Executing endpoint qc_getconfig Dec 31 11:33:32 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 31 11:33:32 rivoplus sudo[5250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 31 11:33:32 rivoplus sudo[5250]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:32 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 31 11:33:32 rivoplus systemd[1]: shairport-sync.service: Succeeded. Dec 31 11:33:32 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.944 [5244.5244] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 31 11:33:32 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 31 11:33:32 rivoplus sudo[5250]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.959 [5244.5244] INFO VolumeManager: [0xac681240]: Setting new playback volume: 75 Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.959 [5244.5244] INFO VolumeManager: [0xac681240]: Setting new mute state: 0 Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.959 [5244.5244] INFO QobuzConnect: [0xac681c10]: Client initialized! Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.960 [5244.5244] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.994 [5244.5244] INFO LocalConfigManager: [0xac680b20]: Starting Local Configuration server Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.994 [5244.5244] INFO SampleApp: Starting Local configuration server Dec 31 11:33:32 rivoplus qobuz-connect[5244]: 20251231 11:33:32.995 [5244.5244] INFO SampleApp: Connected to UNIX socket client 0xac676ed8 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 31 11:33:33 rivoplus volumio[3203]: info: Not Reporting Auto name since its the default one Dec 31 11:33:33 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:33 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/2f68bb8d6a6bf3145d4ca8e886a20dcc.jpg","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1767148408660,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:33 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:33 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/2f68bb8d6a6bf3145d4ca8e886a20dcc.jpg","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1767148408660,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:33 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:33 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:33 rivoplus volumio[3203]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 31 11:33:33 rivoplus volumio[3203]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 31 11:33:33 rivoplus volumio[3203]: info: Shairport-Sync Started Dec 31 11:33:33 rivoplus qobuz-connect[5244]: 20251231 11:33:33.094 [5244.5244] INFO SampleApp: Playback volume changed: 75 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:33 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Dec 31 11:33:33 rivoplus volumio[3203]: No protocol specified Dec 31 11:33:33 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:33 rivoplus sudo[5265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Dec 31 11:33:33 rivoplus sudo[5265]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:33 rivoplus sudo[5265]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:33 rivoplus sudo[5267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Dec 31 11:33:33 rivoplus sudo[5267]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:33 rivoplus systemd[1]: Stopping RAAT DAEMON... Dec 31 11:33:33 rivoplus systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:33 rivoplus systemd[1]: raat-daemon.service: Succeeded. Dec 31 11:33:33 rivoplus systemd[1]: Stopped RAAT DAEMON. Dec 31 11:33:33 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:33 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:33 rivoplus systemd[1]: Started RAAT DAEMON. Dec 31 11:33:33 rivoplus sudo[5267]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:33 rivoplus volumio[3203]: info: Raat Daemon started successfully Dec 31 11:33:33 rivoplus volumio[3203]: info: Executing endpoint restartRAATSocket Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 31 11:33:33 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:33 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Dec 31 11:33:33 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 31 11:33:33 rivoplus qobuz-connect[5244]: 20251231 11:33:33.952 [5244.5281] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:33 rivoplus qobuz-connect[5244]: 20251231 11:33:33.969 [5244.5281] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Sonata for Piano and Violin in F Major, K. 376: I. Allegro","artist":"Hilary Hahn / Natalie Zhu / Wolfgang Amadeus Mozart","album":"Mozart: Violin Sonatas K.301, 304, 376 & 526","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/2f68bb8d6a6bf3145d4ca8e886a20dcc.jpg","uri":"","trackType":"","seek":136000,"duration":307,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1767148413073,"random":false,"repeat":false,"repeatSingle":false} Dec 31 11:33:34 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService pause Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:34 rivoplus sudo[5291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 31 11:33:34 rivoplus sudo[5291]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:34 rivoplus systemd[1]: Started Volumio Tidal Connect Service. Dec 31 11:33:34 rivoplus sudo[5291]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:34 rivoplus mpd[5236]: Dec 31 11:33 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 31 11:33:34 rivoplus systemd[1]: Started Music Player Daemon. Dec 31 11:33:34 rivoplus sudo[5210]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:34 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:34 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 31 11:33:34 rivoplus volumio[3203]: error: updateQueue error: null Dec 31 11:33:34 rivoplus volumio[3203]: info: Executing endpoint tc_getconfig Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 31 11:33:34 rivoplus vtcs[5293]: STARTING TidalConnect services, version: 1.5.2.56 Dec 31 11:33:34 rivoplus vtcs[5293]: STARTED TidalConnect services. Dec 31 11:33:34 rivoplus volumio[3203]: info: Executing endpoint tc_connect Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 31 11:33:34 rivoplus volumio[3203]: info: Connecting to TidalConnect Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: 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 31 11:33:34 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService stop Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: No code Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::servicePushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: 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 31 11:33:34 rivoplus volumio[3203]: verbose: CURRENT POSITION 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::syncState stateService stop Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::syncState currentStatus stop Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: No code Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:34 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:34 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreStateMachine::getcurrentVolume Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::volumioRetrievevolume Dec 31 11:33:34 rivoplus volumio[3203]: info: RAAT: Requesting Headphone Status Dec 31 11:33:34 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:34 rivoplus volumio[3203]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified Dec 31 11:33:34 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:35 rivoplus volumio[3203]: info: MCU Signalled Headphone Mode Disabled Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Dec 31 11:33:35 rivoplus volumio[3203]: info: Reporting Headphone State: false Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:35 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:35 rivoplus volumio[3203]: info: VolumeController:: Volume=undefined Mute =false Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:35 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:35 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:35 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:35 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreStateMachine::updateTrackBlock Dec 31 11:33:35 rivoplus volumio[3203]: info: CorePlayQueue::getTrackBlock Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::volumioRetrievevolume Dec 31 11:33:35 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:35 rivoplus volumio[3203]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified Dec 31 11:33:35 rivoplus volumio[3203]: xcb_connection_has_error() returned true Dec 31 11:33:35 rivoplus volumio[3203]: info: VolumeController:: Volume=undefined Mute =false Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreStateMachine::pushState Dec 31 11:33:35 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::volumioPushState Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:35 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:35 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output update for this device Dec 31 11:33:35 rivoplus volumio[3203]: info: MRS: Pushing multiroomSync output Dec 31 11:33:35 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:35 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:35 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:35 rivoplus volumio[3203]: info: TidalConnect service stoped! Dec 31 11:33:35 rivoplus volumio[3203]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:35 rivoplus volumio[3203]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 31 11:33:35 rivoplus sudo[5329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 31 11:33:35 rivoplus sudo[5329]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:35 rivoplus sudo[5329]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Dec 31 11:33:35 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 31 11:33:36 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:36 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:36 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 31 11:33:36 rivoplus volumio[3203]: info: RAAT: Requesting Headphone Status Dec 31 11:33:36 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Dec 31 11:33:36 rivoplus volumio[3203]: info: MCU Signalled Headphone Mode Disabled Dec 31 11:33:36 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Dec 31 11:33:36 rivoplus volumio[3203]: info: Reporting Headphone State: false Dec 31 11:33:36 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 31 11:33:36 rivoplus volumio[3203]: info: Updating RAAT Signal Path Dec 31 11:33:36 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:36 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:37 rivoplus volumio[3203]: info: TidalConnect service started! Dec 31 11:33:37 rivoplus sudo[5351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 31 11:33:37 rivoplus sudo[5351]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 31 11:33:37 rivoplus systemd[1]: Stopping MPD Monitor Service... Dec 31 11:33:37 rivoplus systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 31 11:33:37 rivoplus systemd[1]: mpd_monitor.service: Succeeded. Dec 31 11:33:37 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 31 11:33:37 rivoplus systemd[1]: Stopped MPD Monitor Service. Dec 31 11:33:37 rivoplus volumio[3203]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 31 11:33:37 rivoplus systemd[1]: Started MPD Monitor Service. Dec 31 11:33:37 rivoplus sudo[5351]: pam_unix(sudo:session): session closed for user root Dec 31 11:33:37 rivoplus volumio[3203]: info: Successfully started MPD Monitor Dec 31 11:33:37 rivoplus mpd_monitor.sh[5353]: MPD Monitor Service: Starting MPD Monitor Service Dec 31 11:33:37 rivoplus qobuz-connect[5244]: 20251231 11:33:37.946 [5244.5281] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:37 rivoplus qobuz-connect[5244]: 20251231 11:33:37.971 [5244.5281] INFO SampleApp: API endpoint invoked: get-display-info Dec 31 11:33:38 rivoplus volumio[3203]: info: TidalConnect service started! Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 31 11:33:38 rivoplus volumio[3203]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 31 11:33:38 rivoplus volumio[3203]: info: Received Get System Version Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 31 11:33:38 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:33:38 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:33:38 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:33:38 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:33:40 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:33:40.239Z level=INFO msg="get music provider auth URI" component=server type=REQUEST_TYPE_GET_MUSIC_PROVIDER_AUTH_URI peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=-738.884µs timeout=10s provider=qobuz Dec 31 11:33:40 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:40 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:33:40 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:33:41 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Dec 31 11:33:41 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 31 11:33:41 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:41 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:41 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 31 11:33:42 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:42 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:33:53 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Dec 31 11:33:53 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 31 11:33:53 rivoplus systemd[1]: systemd-timedated.service: Succeeded. Dec 31 11:33:53 rivoplus volumio-remote-updater[2836]: No test mode Dec 31 11:33:53 rivoplus volumio-remote-updater[2836]: No alpha test mode Dec 31 11:33:53 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 31 11:33:54 rivoplus volumio[3203]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 31 11:33:54 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 31 11:34:04 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:34:04.707Z level=INFO msg="enable music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=1.466586ms timeout=10s provider=qobuz Dec 31 11:34:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:04 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:06 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:34:06 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:34:06 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:34:06 rivoplus volumio[3203]: info: Received OAUTH Data Dec 31 11:34:06 rivoplus volumio[3203]: info: Refreshing QOBUZ token Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:06 rivoplus volumio[3203]: info: Access Token successfully retrieved Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 31 11:34:06 rivoplus volumio[3203]: info: [1767148446214] CoreMusicLibrary::Adding element QOBUZ Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 31 11:34:06 rivoplus volumio[3203]: Cannot find translation for source QOBUZ Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:34:06 rivoplus volumio[3203]: info: Retrieving Cloud Streaming UI Dec 31 11:34:06 rivoplus volumio[3203]: info: Getting Tidal Cloud Configuration Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:34:06 rivoplus volumio[3203]: info: Getting Qobuz Cloud Configuration Dec 31 11:34:06 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:34:06 rivoplus volumio[3203]: info: Getting Spotify Cloud Configuration Dec 31 11:34:06 rivoplus volumio[3203]: info: Asking plugin for UI Config Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:34:06 rivoplus volumio[3203]: info: Saving Spotify Acccount Dec 31 11:34:06 rivoplus volumio[3203]: info: Got it Dec 31 11:34:06 rivoplus volumio[3203]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 31 11:34:06 rivoplus volumio[3203]: info: Got Tidal Cloud Configuration Dec 31 11:34:06 rivoplus volumio[3203]: info: Got it Dec 31 11:34:06 rivoplus volumio[3203]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 31 11:34:09 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:34:09.390Z level=INFO msg="enable music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=27.51738ms timeout=10s provider=spotify Dec 31 11:34:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:09 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:10 rivoplus volumio[3203]: info: Received Get System Info Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 31 11:34:10 rivoplus volumio[3203]: info: Discovery: Getting this device information Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::volumioGetState Dec 31 11:34:10 rivoplus volumio[3203]: info: CorePlayQueue::getTrack 0 Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 31 11:34:10 rivoplus volumio5-onboarding[3970]: time=2025-12-31T02:34:10.214Z level=INFO msg="installing required plugin for music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="00:00:00:00:00:00%01,192.168.0.19:51112 @ 0x1f7ea80" latency=27.51738ms timeout=10s provider=spotify plugin=spop Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:10 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:11 rivoplus volumio[3203]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/rivoplus/buster/armhf Dec 31 11:34:13 rivoplus volumio[3203]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/rivoplus/buster/armhf Dec 31 11:34:13 rivoplus volumio[3203]: info: Folder /tmp/plugins removed Dec 31 11:34:13 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:13 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:13 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:14 rivoplus volumio[3203]: info: Check plugin dependencies Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 31 11:34:14 rivoplus volumio[3203]: info: Checking if plugin already exists Dec 31 11:34:14 rivoplus volumio[3203]: info: Rename folder Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:14 rivoplus volumio[3203]: info: Folder /tmp/downloaded_plugin.zip removed Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:14 rivoplus volumio[3203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 31 11:34:14 rivoplus volumio[3203]: info: Move to category Dec 31 11:34:14 rivoplus volumio[3203]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 31 11:34:14 rivoplus volumio[3203]: Error: ENOENT: no such file or directory, stat '/data/plugins//spop' Dec 31 11:34:14 rivoplus volumio[3203]: at Object.statSync (fs.js:1132:3) Dec 31 11:34:14 rivoplus volumio[3203]: at Object.statSync (/volumio/node_modules/graceful-fs/polyfills.js:308:16) Dec 31 11:34:14 rivoplus volumio[3203]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1632:24) Dec 31 11:34:14 rivoplus volumio[3203]: at CoreCommandRouter.getInstalledPlugins (/volumio/app/index.js:1540:29) Dec 31 11:34:14 rivoplus volumio[3203]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1353:45) Dec 31 11:34:14 rivoplus volumio[3203]: at Socket.emit (events.js:400:28) Dec 31 11:34:14 rivoplus volumio[3203]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Dec 31 11:34:14 rivoplus volumio[3203]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Dec 31 11:34:14 rivoplus volumio[3203]: errno: -2, Dec 31 11:34:14 rivoplus volumio[3203]: syscall: 'stat', Dec 31 11:34:14 rivoplus volumio[3203]: code: 'ENOENT', Dec 31 11:34:14 rivoplus volumio[3203]: path: '/data/plugins//spop' Dec 31 11:34:14 rivoplus volumio[3203]: } Dec 31 11:34:14 rivoplus volumio[3203]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 31 11:34:15 rivoplus sudo[5523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-31 11:33 Dec 31 11:34:15 rivoplus sudo[5523]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:47:33 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="9e8aa5d6afb5e5d87a87bafae7aa5647"