-- Logs begin at Mon 2025-01-20 16:11:31 GMT, end at Mon 2025-01-20 16:23:34 GMT. -- Jan 20 16:22:00 rivo volumio[3223]: info: CALLMETHOD: system_controller network saveWirelessNet [object Object] Jan 20 16:22:00 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNet Jan 20 16:22:00 rivo sudo[8622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/network/interfaces Jan 20 16:22:00 rivo sudo[8622]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:00 rivo sudo[8622]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:00 rivo sudo[8624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/dhcpcd.conf Jan 20 16:22:00 rivo sudo[8624]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:00 rivo sudo[8624]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:00 rivo volumio[3223]: info: Permissions for /etc/network/interfaces set Jan 20 16:22:00 rivo volumio[3223]: info: Restarting Wireless Network Jan 20 16:22:00 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Jan 20 16:22:00 rivo volumio[3223]: info: Discovery: Restarting Advertising due to device name change Jan 20 16:22:00 rivo sudo[8627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Jan 20 16:22:00 rivo sudo[8627]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:00 rivo wpa_supplicant[7462]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Jan 20 16:22:00 rivo systemd[1]: Stopping Wireless Services... Jan 20 16:22:00 rivo wpa_supplicant[7462]: nl80211: Failed to set IPv4 unicast in multicast filter Jan 20 16:22:00 rivo wpa_supplicant[7462]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Jan 20 16:22:00 rivo wpa_supplicant[7462]: nl80211: Failed to set IPv4 unicast in multicast filter Jan 20 16:22:00 rivo wpa_supplicant[7462]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Jan 20 16:22:00 rivo volumio[3223]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 20 16:22:00 rivo wpa_supplicant[7462]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Jan 20 16:22:00 rivo kernel: [35B blob data] Jan 20 16:22:00 rivo kernel: Exit. P2P interface stopped Jan 20 16:22:00 rivo kernel: CFG80211-ERROR) wl_cfg80211_disconnect : Reason 3 Jan 20 16:22:00 rivo kernel: dhd_dbg_stop_pkt_monitor, 1963 Jan 20 16:22:00 rivo kernel: wl_iw_event: Link Down with 30:5a:3a:5b:f8:24, reason=2 Jan 20 16:22:00 rivo kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_LINK Jan 20 16:22:00 rivo kernel: link down if wlan0 may call cfg80211_disconnected. event : 16, reason=2 from 30:5a:3a:5b:f8:24 Jan 20 16:22:00 rivo kernel: dhd_dbg_stop_pkt_monitor, 1963 Jan 20 16:22:00 rivo kernel: CFG80211-ERROR) wl_cfg80211_tdls_config : No change in tdls state. Do nothing. tdls_enable:1 Jan 20 16:22:00 rivo wpa_supplicant[7462]: wlan0: CTRL-EVENT-DISCONNECTED bssid=30:5a:3a:5b:f8:24 reason=3 locally_generated=1 Jan 20 16:22:00 rivo dhcpcd[3571]: wlan0: carrier lost Jan 20 16:22:00 rivo wpa_supplicant[7462]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Jan 20 16:22:00 rivo kernel: dhd_stop: Enter ffffffc05167c000 Jan 20 16:22:00 rivo kernel: CFGP2P-ERROR) wl_cfgp2p_disable_discovery : do nothing, not initialized Jan 20 16:22:00 rivo kernel: CFG80211-ERROR) wl_cfgp2p_down : Clean up the p2p discovery IF Jan 20 16:22:00 rivo kernel: wl_cfgp2p_del_p2p_disc_if: wdev: ffffffc04de82800, wdev->net: (null) Jan 20 16:22:00 rivo kernel: P2P interface unregistered Jan 20 16:22:00 rivo kernel: CFGP2P-ERROR) wl_cfgp2p_deinit_priv : In Jan 20 16:22:00 rivo kernel: dhd_tcpack_suppress_set: TCP ACK Suppress mode 1 -> mode 0 Jan 20 16:22:00 rivo kernel: wl_android_wifi_off in 1 Jan 20 16:22:00 rivo kernel: wl_android_wifi_off in 2: g_wifi_on=1, on_failure=1 Jan 20 16:22:00 rivo kernel: dhd_dbg_detach_pkt_monitor, 2204 Jan 20 16:22:00 rivo kernel: dhd_bus_devreset: == Power OFF == Jan 20 16:22:00 rivo kernel: bcmsdh_oob_intr_unregister: Enter Jan 20 16:22:00 rivo kernel: dhd_txglom_enable: enable 0 Jan 20 16:22:00 rivo kernel: dhd_conf_set_txglom_params: txglom_mode=copy Jan 20 16:22:00 rivo kernel: dhd_conf_set_txglom_params: txglomsize=0, deferred_tx_len=0 Jan 20 16:22:00 rivo kernel: dhd_conf_set_txglom_params: txinrx_thres=128, dhd_txminmax=-1 Jan 20 16:22:00 rivo kernel: dhd_conf_set_txglom_params: tx_max_offset=0, txctl_tmo_fix=300 Jan 20 16:22:00 rivo kernel: dhd_bus_devreset: WLAN OFF DONE Jan 20 16:22:00 rivo kernel: wifi_platform_set_power = 0 Jan 20 16:22:00 rivo kernel: ======== PULL WL_REG_ON(-1) LOW! ======== Jan 20 16:22:00 rivo kernel: aml_wifi wifi: [extern_wifi_set_enable] WIFI Disable! 482 Jan 20 16:22:00 rivo kernel: wl_android_wifi_off out Jan 20 16:22:00 rivo kernel: wl_ext_iapsta_dettach_netdev: Enter Jan 20 16:22:00 rivo kernel: dhd_stop: Exit Jan 20 16:22:00 rivo avahi-daemon[2862]: Interface wlan0.IPv4 no longer relevant for mDNS. Jan 20 16:22:00 rivo avahi-daemon[2862]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.217. Jan 20 16:22:00 rivo wpa_supplicant[7462]: wlan0: CTRL-EVENT-TERMINATING Jan 20 16:22:00 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:00 rivo systemd[1]: wireless.service: Succeeded. Jan 20 16:22:00 rivo systemd[1]: Stopped Wireless Services. Jan 20 16:22:00 rivo avahi-daemon[2862]: Withdrawing address record for 192.168.1.217 on wlan0. Jan 20 16:22:00 rivo volumio[3223]: info: Discovery: A device disappeared from network Jan 20 16:22:00 rivo volumio[3223]: info: Discovery: Device rivo disappeared from network Jan 20 16:22:00 rivo systemd[1]: Starting Wireless Services... Jan 20 16:22:00 rivo volumio[3223]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 20 16:22:00 rivo dhcpcd[3571]: wlan0: deleting route to 192.168.1.0/24 Jan 20 16:22:00 rivo dhcpcd[3571]: wlan0: deleting default route via 192.168.1.254 Jan 20 16:22:00 rivo volumio[3223]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 20 16:22:01 rivo dhcpcd[3571]: wlan0: carrier acquired Jan 20 16:22:01 rivo dhcpcd[3571]: wlan0: confile file changed, expiring leases Jan 20 16:22:01 rivo dhcpcd[3571]: wlan0: IAID 32:e3:94:40 Jan 20 16:22:01 rivo dhcpcd[3571]: wlan0: carrier lost Jan 20 16:22:01 rivo volumio[3223]: info: Discovery: A device disappeared from network Jan 20 16:22:01 rivo wireless.js[8647]: Cleaning previous... Jan 20 16:22:01 rivo sudo[8703]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 20 16:22:01 rivo sudo[8703]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:01 rivo sudo[8703]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:01 rivo sudo[8706]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 20 16:22:01 rivo sudo[8706]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:01 rivo sudo[8706]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:02 rivo wireless.js[8647]: Stopped aP Jan 20 16:22:02 rivo wireless.js[8647]: Wireless Networking DISABLED, not starting wireless flow Jan 20 16:22:02 rivo iw[8713]: command failed: Input/output error (-5) Jan 20 16:22:02 rivo iwconfig[8714]: Error for wireless request "Set Power Management" (8B2C) : Jan 20 16:22:02 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:02 rivo iwconfig[8714]: SET failed on device wlan0 ; Invalid argument. Jan 20 16:22:02 rivo systemd[1]: wireless.service: Succeeded. Jan 20 16:22:02 rivo systemd[1]: Started Wireless Services. Jan 20 16:22:02 rivo sudo[8627]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:02 rivo ntpd[7590]: Deleting interface #4 wlan0, 192.168.1.217#123, interface stats: received=0, sent=0, dropped=0, active_time=226 secs Jan 20 16:22:05 rivo volumio[3223]: info: Discovery: Started advertising with name: Rivo Jan 20 16:22:06 rivo volumio[3223]: info: Discovery: adding 0152fe23-21c3-46d6-81b7-9403e5cc8984 Jan 20 16:22:06 rivo volumio[3223]: info: Discovery: Found device Rivo Jan 20 16:22:06 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:07 rivo volumio[3223]: info: Reporting MCU Network Status: 1 Jan 20 16:22:07 rivo volumio[3223]: info: Volumio Network Manager: Network status updated: 1 Jan 20 16:22:07 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Jan 20 16:22:07 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Jan 20 16:22:07 rivo sudo[8744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 16:22:07 rivo sudo[8744]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:07 rivo sudo[8744]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:12 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Jan 20 16:22:12 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Jan 20 16:22:12 rivo volumio[3223]: info: Refreshing Cached IP Addresses Jan 20 16:22:12 rivo sudo[8748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Jan 20 16:22:12 rivo sudo[8748]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:12 rivo sudo[8748]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:12 rivo sudo[8751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 16:22:12 rivo sudo[8751]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:12 rivo volumio[3223]: error: Upnp client error: Error: This socket has been ended by the other party Jan 20 16:22:12 rivo sudo[8751]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:12 rivo sudo[8755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 16:22:12 rivo sudo[8755]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:12 rivo sudo[8755]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:12 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:12 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:12 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:12 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:12 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:13 rivo sudo[8762]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 16:22:13 rivo sudo[8762]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:13 rivo sudo[8762]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:13 rivo sudo[8766]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 16:22:13 rivo sudo[8766]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:13 rivo sudo[8766]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:13 rivo volumio[3223]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.160 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 9 Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::volumioGetVisibleSources Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 20 16:22:13 rivo volumio[3223]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 20 16:22:13 rivo volumio[3223]: info: Received Get System Info Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:13 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:13 rivo volumio[3223]: info: Listing playlists Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 20 16:22:13 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 20 16:22:14 rivo sudo[8773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 20 16:22:14 rivo sudo[8773]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:14 rivo sudo[8773]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:14 rivo sudo[8777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 20 16:22:14 rivo sudo[8777]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: Error getting the SSID Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo sudo[8777]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:14 rivo sudo[8785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 20 16:22:14 rivo sudo[8785]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:14 rivo sudo[8785]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: Error getting the SSID Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo sudo[8795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 20 16:22:14 rivo sudo[8795]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:14 rivo sudo[8795]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: Error getting the SSID Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo kernel: dhd_ioctl_entry: Interface is down Jan 20 16:22:14 rivo sudo[8801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 16:22:14 rivo sudo[8801]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:14 rivo sudo[8801]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:14 rivo sudo[8806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 16:22:14 rivo sudo[8806]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:14 rivo sudo[8806]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 16:22:14 rivo volumio[3223]: info: Received Get System Info Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:14 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:14 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:15 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 20 16:22:16 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 16:22:16 rivo volumio[3223]: info: Received Get System Info Jan 20 16:22:16 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:16 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:16 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:16 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:16 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:22 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:22 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:22 rivo sudo[8828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 16:22:22 rivo sudo[8828]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:22 rivo sudo[8828]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:22 rivo sudo[8832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 16:22:22 rivo sudo[8832]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:22 rivo sudo[8832]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:22 rivo sudo[8834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 20 16:22:22 rivo sudo[8834]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:22:22 rivo sudo[8834]: pam_unix(sudo:session): session closed for user root Jan 20 16:22:22 rivo volumio[3223]: info: Upmpdcli Daemon Started Jan 20 16:22:23 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 20 16:22:25 rivo volumio[3223]: info: CoreCommandRouter::Close All Modals sent Jan 20 16:22:25 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , setTOSAccepted Jan 20 16:22:28 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:28 rivo volumio[3223]: info: CoreCommandRouter::volumioPlay Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::play index undefined Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 16:22:28 rivo volumio[3223]: info: CorePlayQueue::getTrack 0 Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::startPlaybackTimer Jan 20 16:22:28 rivo volumio[3223]: info: CorePlayQueue::getTrack 0 Jan 20 16:22:28 rivo volumio[3223]: info: [1737390148564] ControllerTidal::resume Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 20 16:22:28 rivo volumio[3223]: info: ControllerMpd::resume Jan 20 16:22:28 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand play Jan 20 16:22:28 rivo volumio[3223]: info: Jan 20 16:22:28 rivo volumio[3223]: ---------------------------- MPD announces state update: player Jan 20 16:22:28 rivo volumio[3223]: info: sendMpdCommand play took 42 milliseconds Jan 20 16:22:28 rivo volumio[3223]: info: ControllerMpd::getState Jan 20 16:22:28 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand status Jan 20 16:22:28 rivo volumio[3223]: info: sendMpdCommand status took 2 milliseconds Jan 20 16:22:28 rivo volumio[3223]: verbose: ControllerMpd::parseState Jan 20 16:22:28 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 16:22:28 rivo volumio[3223]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 20 16:22:28 rivo volumio[3223]: verbose: ControllerMpd::parseTrackInfo Jan 20 16:22:28 rivo volumio[3223]: info: ControllerMpd::pushState Jan 20 16:22:28 rivo volumio[3223]: info: CoreCommandRouter::servicePushState Jan 20 16:22:28 rivo volumio[3223]: info: CorePlayQueue::getTrack 0 Jan 20 16:22:28 rivo volumio[3223]: verbose: STATE SERVICE {"status":"play","position":0,"seek":8731,"duration":33,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1517 Kbps","isStreaming":false,"title":"410123229&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/410123229&soundQuality=HI_RES","trackType":"tidal"} Jan 20 16:22:28 rivo volumio[3223]: verbose: CURRENT POSITION 0 Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::syncState stateService play Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::syncState currentStatus pause Jan 20 16:22:28 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:28 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 16:22:28 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:28 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:28 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:28 rivo volumio[3223]: info: ------------------------------ 56ms Jan 20 16:22:28 rivo volumio[3223]: info: Signalling Playback active due to playback status change Jan 20 16:22:28 rivo volumio[3223]: info: MCU Signalled Playback Active Jan 20 16:22:30 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:30 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:30 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:30 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:30 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:30 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 16:22:31 rivo volumio[3223]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 20 16:22:31 rivo volumio[3223]: info: Received Get System Version Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 16:22:31 rivo volumio[3223]: info: Received Get System Info Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:31 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::volumioNext Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::next Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::next Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand next Jan 20 16:22:35 rivo volumio[3223]: info: Jan 20 16:22:35 rivo volumio[3223]: ---------------------------- MPD announces state update: player Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand next took 36 milliseconds Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::getState Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand status Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand status took 1 milliseconds Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::parseState Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::servicePushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 0 Jan 20 16:22:35 rivo volumio[3223]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jan 20 16:22:35 rivo volumio[3223]: verbose: CURRENT POSITION 0 Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::syncState stateService stop Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::syncState currentStatus play Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::play index undefined Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::startPlaybackTimer Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:35 rivo volumio[3223]: info: [1737390155256] ControllerTidal::clearAddPlayTrack Jan 20 16:22:35 rivo volumio[3223]: info: Getting stream with soundQuality HI_RES Jan 20 16:22:35 rivo volumio[3223]: info: ------------------------------ 65ms Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand stop Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand stop took 22 milliseconds Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand clear Jan 20 16:22:35 rivo volumio[3223]: info: Jan 20 16:22:35 rivo volumio[3223]: ---------------------------- MPD announces system playlist update Jan 20 16:22:35 rivo volumio[3223]: info: Ignoring MPD Status Update Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand clear took 34 milliseconds Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/410123230&soundQuality=HI_RES" Jan 20 16:22:35 rivo volumio[3223]: error: updateQueue error: null Jan 20 16:22:35 rivo volumio[3223]: info: Jan 20 16:22:35 rivo volumio[3223]: ---------------------------- MPD announces system playlist update Jan 20 16:22:35 rivo volumio[3223]: info: Ignoring MPD Status Update Jan 20 16:22:35 rivo volumio[3223]: info: ------------------------------ 8ms Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/410123230&soundQuality=HI_RES" took 7 milliseconds Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand play Jan 20 16:22:35 rivo volumio[3223]: info: ------------------------------ 6ms Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand play took 3 milliseconds Jan 20 16:22:35 rivo volumio[3223]: STREAMING PROXY: Handling url /?data=tidal://song/410123230&soundQuality=HI_RES Jan 20 16:22:35 rivo volumio[3223]: info: Executing endpoint getStreamUrltidal Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Jan 20 16:22:35 rivo volumio[3223]: info: MCU Signalled Playback Inactive Jan 20 16:22:35 rivo volumio[3223]: info: getStreamUrl took 388 milliseconds Jan 20 16:22:35 rivo volumio[3223]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiQwZmUzYjRmZjk5MGY5ZWEzODEwM2M5MzEyMDYyNWEwOS5tcDQ/0.flac?Expires=1737393755&Signature=Iu9x6laCkmvZsk84Kfpl041TrOIKaNrETTZio1NFSkvNk6085-38vmZXcl4aSM~mDRghh9jSNZFozCGsJkkSYAoSUhUZstCsMPLh8SE8oW-ZAfTd9SYNgZGt53iCHMJO31ZH0iNp6FL3X1Rdq3R4JBR0kIghYk1ZyxWqWy5IGX13bcHaGKcz5M8DwKZ-LGyVNkBXMFf9BKquXkKEBFd7WCpuYBgevHifLCfaVkXpJsphk3ROntFjZxzRbmar9gvlXqt2F08w1DZ5FOjnFIdUcN~SWMnpdBgqLYQ1I0WttMFyCIW~ZfolHxSu5kmu~SktPNrVFGMVtPL6uWxGrIr~VA__&Key-Pair-Id=K14LZCZ9QUI4JL Jan 20 16:22:35 rivo volumio[3223]: STREAMING PROXY: Response: 200, length: 57001941 Jan 20 16:22:35 rivo volumio[3223]: info: Jan 20 16:22:35 rivo volumio[3223]: ---------------------------- MPD announces state update: player Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::getState Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand status Jan 20 16:22:35 rivo volumio[3223]: info: Jan 20 16:22:35 rivo volumio[3223]: ---------------------------- MPD announces state update: player Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand status took 21 milliseconds Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::getState Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand status Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::parseState Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand status took 20 milliseconds Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::parseState Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::parseTrackInfo Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::servicePushState Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:35 rivo volumio[3223]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":316,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"410123230&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/410123230&soundQuality=HI_RES","trackType":"tidal"} Jan 20 16:22:35 rivo volumio[3223]: verbose: CURRENT POSITION 1 Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::syncState stateService play Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::syncState currentStatus stop Jan 20 16:22:35 rivo volumio[3223]: info: ------------------------------ 67ms Jan 20 16:22:35 rivo volumio[3223]: info: sendMpdCommand playlistinfo took 18 milliseconds Jan 20 16:22:35 rivo volumio[3223]: verbose: ControllerMpd::parseTrackInfo Jan 20 16:22:35 rivo volumio[3223]: info: ControllerMpd::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::servicePushState Jan 20 16:22:35 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:35 rivo volumio[3223]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1234,"duration":316,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1154 Kbps","isStreaming":false,"title":"410123230&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/410123230&soundQuality=HI_RES","trackType":"tidal"} Jan 20 16:22:35 rivo volumio[3223]: verbose: CURRENT POSITION 1 Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::syncState stateService play Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::syncState currentStatus play Jan 20 16:22:35 rivo volumio[3223]: info: Received an update from plugin. extracting info from payload Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:35 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:35 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:35 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:35 rivo volumio[3223]: info: ------------------------------ 131ms Jan 20 16:22:35 rivo volumio[3223]: info: Signalling Playback active due to playback status change Jan 20 16:22:36 rivo volumio[3223]: info: MCU Signalled Playback Active Jan 20 16:22:36 rivo volumio[3223]: info: CoreCommandRouter::volumioPause Jan 20 16:22:36 rivo volumio[3223]: info: CoreStateMachine::pause Jan 20 16:22:36 rivo volumio[3223]: info: CoreStateMachine::stPlaybackTimer Jan 20 16:22:36 rivo volumio[3223]: info: CoreStateMachine::servicePause Jan 20 16:22:36 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:36 rivo volumio[3223]: info: CoreCommandRouter::servicePause Jan 20 16:22:36 rivo volumio[3223]: info: [1737390156997] ControllerTidal::pause Jan 20 16:22:36 rivo volumio[3223]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 20 16:22:36 rivo volumio[3223]: info: ControllerMpd::pause Jan 20 16:22:36 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand pause Jan 20 16:22:37 rivo volumio[3223]: info: Jan 20 16:22:37 rivo volumio[3223]: ---------------------------- MPD announces state update: player Jan 20 16:22:37 rivo volumio[3223]: info: sendMpdCommand pause took 3 milliseconds Jan 20 16:22:37 rivo volumio[3223]: info: ControllerMpd::getState Jan 20 16:22:37 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand status Jan 20 16:22:37 rivo volumio[3223]: info: sendMpdCommand status took 2 milliseconds Jan 20 16:22:37 rivo volumio[3223]: verbose: ControllerMpd::parseState Jan 20 16:22:37 rivo volumio[3223]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 16:22:37 rivo volumio[3223]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 20 16:22:37 rivo volumio[3223]: verbose: ControllerMpd::parseTrackInfo Jan 20 16:22:37 rivo volumio[3223]: info: ControllerMpd::pushState Jan 20 16:22:37 rivo volumio[3223]: info: CoreCommandRouter::servicePushState Jan 20 16:22:37 rivo volumio[3223]: info: CorePlayQueue::getTrack 1 Jan 20 16:22:37 rivo volumio[3223]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2480,"duration":316,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1216 Kbps","isStreaming":false,"title":"410123230&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/410123230&soundQuality=HI_RES","trackType":"tidal"} Jan 20 16:22:37 rivo volumio[3223]: verbose: CURRENT POSITION 1 Jan 20 16:22:37 rivo volumio[3223]: info: CoreStateMachine::syncState stateService pause Jan 20 16:22:37 rivo volumio[3223]: info: CoreStateMachine::syncState currentStatus pause Jan 20 16:22:37 rivo volumio[3223]: info: CoreStateMachine::pushState Jan 20 16:22:37 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 16:22:37 rivo volumio[3223]: info: CoreCommandRouter::volumioPushState Jan 20 16:22:37 rivo volumio[3223]: info: MRS: Pushing multiroomSync output update for this device Jan 20 16:22:37 rivo volumio[3223]: info: MRS: Pushing multiroomSync output Jan 20 16:22:37 rivo volumio[3223]: info: CoreStateMachine::stPlaybackTimer Jan 20 16:22:37 rivo volumio[3223]: info: ------------------------------ 73ms Jan 20 16:22:37 rivo volumio[3223]: info: MCU Signalled Playback Inactive Jan 20 16:22:39 rivo volumio[3223]: info: CoreCommandRouter::volumioGetQueue Jan 20 16:22:39 rivo volumio[3223]: info: CoreStateMachine::getQueue Jan 20 16:22:39 rivo volumio[3223]: info: CorePlayQueue::getQueue Jan 20 16:22:41 rivo volumio[3223]: STREAMING PROXY: Client dropped request, destroying Jan 20 16:22:42 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:45 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:45 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:45 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:45 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:45 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:45 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:47 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:49 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:49 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:49 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:49 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:49 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:22:49 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Jan 20 16:22:51 rivo volumio[3223]: info: Received Get System Version Jan 20 16:22:51 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 16:22:52 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:22:52 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:22:52 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:22:52 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:22:52 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:22:58 rivo nmbd[3086]: [2025/01/20 16:22:58.188303, 0] ../source3/libsmb/nmblib.c:917(send_udp) Jan 20 16:22:58 rivo nmbd[3086]: Packet send failed to 192.168.1.255(138) ERRNO=Network is unreachable Jan 20 16:23:05 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:23:07 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:23:07 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:23:07 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:23:07 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:23:07 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:23:07 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:08 rivo volumio[3223]: No protocol specified Jan 20 16:23:08 rivo volumio[3223]: xcb_connection_has_error() returned true Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 20 16:23:08 rivo volumio[3223]: No protocol specified Jan 20 16:23:08 rivo volumio[3223]: xcb_connection_has_error() returned true Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 16:23:08 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 16:23:18 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:23:21 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:23:21 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:23:21 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:23:21 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:23:21 rivo volumio[3223]: info: Executing endpoint metavolumio Jan 20 16:23:21 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 16:23:22 rivo volumio[3223]: info: Discovery: Getting this device information Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::volumioGetState Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:22 rivo volumio[3223]: info: Retrieving Cloud Streaming UI Jan 20 16:23:22 rivo volumio[3223]: info: Getting Tidal Cloud Configuration Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:22 rivo volumio[3223]: info: Getting Qobuz Cloud Configuration Jan 20 16:23:22 rivo volumio[3223]: info: Asking plugin for UI Config Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:22 rivo volumio[3223]: info: Getting Spotify Cloud Configuration Jan 20 16:23:22 rivo volumio[3223]: info: Asking plugin for UI Config Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:22 rivo volumio[3223]: info: Saving Spotify Acccount Jan 20 16:23:22 rivo volumio[3223]: info: Got it Jan 20 16:23:22 rivo volumio[3223]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 20 16:23:22 rivo volumio[3223]: info: Got Tidal Cloud Configuration Jan 20 16:23:22 rivo volumio[3223]: info: Got it Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 16:23:22 rivo volumio[3223]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 16:23:23 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 20 16:23:23 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 20 16:23:26 rivo volumio[3223]: info: Disabling MyMusic plugin upnp Jan 20 16:23:26 rivo sudo[9020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jan 20 16:23:26 rivo sudo[9020]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 16:23:26 rivo volumio[3223]: error: Upnp client error: Error: This socket has been ended by the other party Jan 20 16:23:26 rivo systemd[1]: Stopping UPnP Renderer front-end to MPD... Jan 20 16:23:26 rivo volumio[3223]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 20 16:23:27 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 20 16:23:31 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 20 16:23:34 rivo volumio[3223]: info: Enabling MyMusic plugin upnp Jan 20 16:23:34 rivo volumio[3223]: info: Enabling plugin upnp Jan 20 16:23:34 rivo volumio[3223]: info: Loading plugin "upnp"... Jan 20 16:23:34 rivo volumio[3223]: info: [1737390214032] Starting Upmpd Daemon Jan 20 16:23:34 rivo volumio[3223]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 20 16:23:34 rivo volumio[3223]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 16:23:34 rivo volumio[3223]: Error: listen EADDRINUSE: address already in use :::6599 Jan 20 16:23:34 rivo volumio[3223]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jan 20 16:23:34 rivo volumio[3223]: at listenInCluster (net.js:1379:12) Jan 20 16:23:34 rivo volumio[3223]: at Server.listen (net.js:1465:7) Jan 20 16:23:34 rivo volumio[3223]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jan 20 16:23:34 rivo volumio[3223]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jan 20 16:23:34 rivo volumio[3223]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jan 20 16:23:34 rivo volumio[3223]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 20 16:23:34 rivo volumio[3223]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jan 20 16:23:34 rivo volumio[3223]: code: 'EADDRINUSE', Jan 20 16:23:34 rivo volumio[3223]: errno: -98, Jan 20 16:23:34 rivo volumio[3223]: syscall: 'listen', Jan 20 16:23:34 rivo volumio[3223]: address: '::', Jan 20 16:23:34 rivo volumio[3223]: port: 6599 Jan 20 16:23:34 rivo volumio[3223]: } Jan 20 16:23:34 rivo volumio[3223]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 16:23:34 rivo sudo[9060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-20 16:22 Jan 20 16:23:34 rivo sudo[9060]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"