-- Logs begin at Thu 2019-02-14 12:11:58 EET, end at Wed 2025-05-14 09:44:23 EEST. -- May 14 09:43:01 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 14 09:43:03 rivoplus kernel: CFG80211-ERROR) wl_cfg80211_disconnect : Reason 3 May 14 09:43:03 rivoplus kernel: dhd_dbg_stop_pkt_monitor, 1963 May 14 09:43:03 rivoplus kernel: wl_iw_event: Link Down with 10:3c:59:bb:35:54, reason=2 May 14 09:43:03 rivoplus kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_LINK May 14 09:43:03 rivoplus kernel: link down if wlan0 may call cfg80211_disconnected. event : 16, reason=2 from 10:3c:59:bb:35:54 May 14 09:43:03 rivoplus kernel: dhd_dbg_stop_pkt_monitor, 1963 May 14 09:43:03 rivoplus kernel: CFG80211-ERROR) wl_cfg80211_tdls_config : No change in tdls state. Do nothing. tdls_enable:1 May 14 09:43:03 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-DISCONNECTED bssid=10:3c:59:bb:35:54 reason=0 May 14 09:43:03 rivoplus dhcpcd[3259]: wlan0: carrier lost May 14 09:43:03 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD May 14 09:43:03 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=BG May 14 09:43:03 rivoplus avahi-daemon[2824]: Withdrawing address record for 192.168.0.103 on wlan0. May 14 09:43:03 rivoplus avahi-daemon[2824]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.103. May 14 09:43:03 rivoplus avahi-daemon[2824]: Interface wlan0.IPv4 no longer relevant for mDNS. May 14 09:43:03 rivoplus volumio[3292]: info: Discovery: A device disappeared from network May 14 09:43:03 rivoplus volumio[3292]: info: Discovery: Device rivoplus disappeared from network May 14 09:43:03 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD May 14 09:43:03 rivoplus dhcpcd[3259]: wlan0: deleting route to 192.168.0.0/24 May 14 09:43:03 rivoplus dhcpcd[3259]: wlan0: deleting default route via 192.168.0.1 May 14 09:43:03 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=BG May 14 09:43:04 rivoplus ntpd[4768]: Deleting interface #3 wlan0, 192.168.0.103#123, interface stats: received=73, sent=79, dropped=0, active_time=57 secs May 14 09:43:04 rivoplus ntpd[4768]: 162.159.200.123 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 213.91.190.205 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 84.54.128.102 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 91.210.88.37 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 185.117.82.66 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 95.43.236.49 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 194.59.28.22 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 185.117.82.71 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 195.85.215.215 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 78.130.168.61 local addr 192.168.0.103 -> May 14 09:43:04 rivoplus ntpd[4768]: 213.91.190.163 local addr 192.168.0.103 -> May 14 09:43:06 rivoplus wpa_supplicant[3173]: wlan0: Trying to associate with 10:3c:59:bb:35:54 (SSID='A1Home' freq=5745 MHz) May 14 09:43:06 rivoplus kernel: Connecting with 10:3c:59:bb:35:54 ssid "A1Home", len (6) channel=149 May 14 09:43:06 rivoplus kernel: dhd_dbg_start_pkt_monitor, 1724 May 14 09:43:06 rivoplus kernel: wl_iw_event: Link UP with 10:3c:59:bb:35:54 May 14 09:43:06 rivoplus kernel: wl_bss_connect_done succeeded with 10:3c:59:bb:35:54 May 14 09:43:06 rivoplus kernel: CFG80211-ERROR) wl_cfg80211_scan_abort : scan abort failed May 14 09:43:06 rivoplus wpa_supplicant[3173]: wlan0: Associated with 10:3c:59:bb:35:54 May 14 09:43:06 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 14 09:43:07 rivoplus wpa_supplicant[3173]: wlan0: WPA: Key negotiation completed with 10:3c:59:bb:35:54 [PTK=CCMP GTK=CCMP] May 14 09:43:07 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-CONNECTED - Connection to 10:3c:59:bb:35:54 completed [id=0 id_str=] May 14 09:43:07 rivoplus dhcpcd[3259]: wlan0: carrier acquired May 14 09:43:07 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=AT May 14 09:43:07 rivoplus dhcpcd[3259]: wlan0: IAID c9:8f:f5:84 May 14 09:43:07 rivoplus kernel: wl_bss_connect_done succeeded with 10:3c:59:bb:35:54 vndr_oui: 8C-FD-F0 May 14 09:43:07 rivoplus volumio[3292]: info: Reporting MCU Network Status: 0 May 14 09:43:07 rivoplus volumio[3292]: info: Volumio Network Manager: Network status updated: 0 May 14 09:43:07 rivoplus dhcpcd[3259]: wlan0: soliciting an IPv6 router May 14 09:43:07 rivoplus dhcpcd[3259]: wlan0: rebinding lease of 192.168.0.103 May 14 09:43:07 rivoplus dhcpcd[3259]: wlan0: probing address 192.168.0.103/24 May 14 09:43:12 rivoplus dhcpcd[3259]: wlan0: leased 192.168.0.103 for 86400 seconds May 14 09:43:12 rivoplus avahi-daemon[2824]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.103. May 14 09:43:12 rivoplus dhcpcd[3259]: wlan0: adding route to 192.168.0.0/24 May 14 09:43:12 rivoplus dhcpcd[3259]: wlan0: adding default route via 192.168.0.1 May 14 09:43:12 rivoplus avahi-daemon[2824]: New relevant interface wlan0.IPv4 for mDNS. May 14 09:43:12 rivoplus avahi-daemon[2824]: Registering new address record for 192.168.0.103 on wlan0.IPv4. May 14 09:43:12 rivoplus ntpd[4768]: ntpd exiting on signal 15 (Terminated) May 14 09:43:12 rivoplus systemd[1]: Stopping Network Time Service... May 14 09:43:12 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:43:12 rivoplus systemd[1]: ntp.service: Succeeded. May 14 09:43:12 rivoplus systemd[1]: Stopped Network Time Service. May 14 09:43:12 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:43:12 rivoplus systemd[1]: Starting Network Time Service... May 14 09:43:12 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:43:12 rivoplus ntpd[5014]: ntpd 4.2.8p12@1.3728-o (1): Starting May 14 09:43:12 rivoplus ntpd[5014]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 14 09:43:12 rivoplus systemd[1]: Started Network Time Service. May 14 09:43:12 rivoplus ntpd[5030]: proto: precision = 1.208 usec (-20) May 14 09:43:12 rivoplus ntpd[5030]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 14 09:43:12 rivoplus ntpd[5030]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 14 09:43:12 rivoplus ntpd[5030]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 869 days ago May 14 09:43:12 rivoplus ntpd[5030]: Listen and drop on 0 v6wildcard [::]:123 May 14 09:43:12 rivoplus ntpd[5030]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 14 09:43:12 rivoplus ntpd[5030]: Listen normally on 2 lo 127.0.0.1:123 May 14 09:43:12 rivoplus ntpd[5030]: Listen normally on 3 wlan0 192.168.0.103:123 May 14 09:43:12 rivoplus ntpd[5030]: Listening on routing socket on fd #20 for interface updates May 14 09:43:12 rivoplus ntpd[5030]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 14 09:43:12 rivoplus ntpd[5030]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 14 09:43:12 rivoplus volumio[3292]: info: MRS: Found cast device: B866V2F02-673d153d0fe5139ea03d0914ec9983f9 May 14 09:43:13 rivoplus volumio[3292]: info: Discovery: adding 5e2a4850-80a7-4a92-950e-09eb5e5fea18 May 14 09:43:13 rivoplus volumio[3292]: info: Discovery: Found device Rivoplus May 14 09:43:13 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:13 rivoplus ntpd[5030]: Soliciting pool server 213.91.190.205 May 14 09:43:14 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 14 09:43:14 rivoplus ntpd[5030]: Soliciting pool server 213.91.190.163 May 14 09:43:14 rivoplus ntpd[5030]: Soliciting pool server 195.85.215.215 May 14 09:43:15 rivoplus ntpd[5030]: Soliciting pool server 185.117.82.71 May 14 09:43:15 rivoplus ntpd[5030]: Soliciting pool server 162.159.200.123 May 14 09:43:15 rivoplus ntpd[5030]: Soliciting pool server 176.12.60.87 May 14 09:43:16 rivoplus ntpd[5030]: Soliciting pool server 185.117.82.66 May 14 09:43:16 rivoplus ntpd[5030]: Soliciting pool server 78.159.131.45 May 14 09:43:16 rivoplus ntpd[5030]: Soliciting pool server 194.59.28.22 May 14 09:43:17 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 14 09:43:17 rivoplus volumio[3292]: info: Reporting MCU Network Status: 2 May 14 09:43:17 rivoplus volumio[3292]: info: Volumio Network Manager: Network status updated: 2 May 14 09:43:17 rivoplus ntpd[5030]: Soliciting pool server 162.159.200.1 May 14 09:43:17 rivoplus ntpd[5030]: Soliciting pool server 77.236.182.128 May 14 09:43:18 rivoplus ntpd[5030]: Soliciting pool server 84.54.128.102 May 14 09:43:19 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri May 14 09:43:19 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetQueue May 14 09:43:19 rivoplus volumio[3292]: info: CoreStateMachine::getQueue May 14 09:43:19 rivoplus volumio[3292]: info: CorePlayQueue::getQueue May 14 09:43:19 rivoplus volumio[3292]: info: Listing playlists May 14 09:43:19 rivoplus ntpd[5030]: Soliciting pool server 2a01:9e40::abcd May 14 09:43:19 rivoplus volumio[3292]: info: browseTIDALUri took 371 milliseconds May 14 09:43:19 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:19 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri May 14 09:43:22 rivoplus volumio[3292]: info: browseTIDALUri took 492 milliseconds May 14 09:43:22 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:23 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:23 rivoplus volumio[3292]: info: CoreCommandRouter::volumioReplaceandPlayItems May 14 09:43:23 rivoplus volumio[3292]: info: CoreStateMachine::ClearQueue May 14 09:43:23 rivoplus volumio[3292]: info: CoreStateMachine::stop May 14 09:43:23 rivoplus volumio[3292]: info: CoreStateMachine::serviceStop May 14 09:43:23 rivoplus volumio[3292]: info: CoreCommandRouter::serviceStop May 14 09:43:23 rivoplus volumio[3292]: info: Airplay Stop May 14 09:43:23 rivoplus volumio[3292]: info: Stopping Airplay Playback and sending pause command to client via USR2 May 14 09:43:23 rivoplus volumio[3292]: info: CorePlayQueue::clearPlayQueue May 14 09:43:23 rivoplus volumio[3292]: info: CorePlayQueue::saveQueue May 14 09:43:23 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushQueue May 14 09:43:23 rivoplus volumio[3292]: info: CoreStateMachine::addQueueItems May 14 09:43:23 rivoplus volumio[3292]: info: CorePlayQueue::addQueueItems May 14 09:43:23 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:23 rivoplus volumio[3292]: info: Adding Item to queue: tidal://mymusic/mixes/00254561d6eca21ab382b7c6952462 May 14 09:43:23 rivoplus volumio[3292]: info: Exploding uri tidal://mymusic/mixes/00254561d6eca21ab382b7c6952462 in service tidal May 14 09:43:23 rivoplus sudo[5077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 May 14 09:43:23 rivoplus sudo[5077]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:43:23 rivoplus sudo[5077]: pam_unix(sudo:session): session closed for user root May 14 09:43:23 rivoplus volumio[3292]: info: Cannot execute Shairport-sync USR2 kill: Error: Command failed: /usr/bin/sudo /bin/kill -USR2 $(pidof shairport-sync) May 14 09:43:23 rivoplus volumio[3292]: Usage: May 14 09:43:23 rivoplus volumio[3292]: kill [options] [...] May 14 09:43:23 rivoplus volumio[3292]: Options: May 14 09:43:23 rivoplus volumio[3292]: [...] send signal to every listed May 14 09:43:23 rivoplus volumio[3292]: -, -s, --signal May 14 09:43:23 rivoplus volumio[3292]: specify the to be sent May 14 09:43:23 rivoplus volumio[3292]: -l, --list=[] list all signal names, or convert one to a name May 14 09:43:23 rivoplus volumio[3292]: -L, --table list all signal names in a nice table May 14 09:43:23 rivoplus volumio[3292]: -h, --help display this help and exit May 14 09:43:23 rivoplus volumio[3292]: -V, --version output version information and exit May 14 09:43:23 rivoplus volumio[3292]: For more details see kill(1). May 14 09:43:24 rivoplus volumio[3292]: info: explodeTIDALUri took 986 milliseconds May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushQueue May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::saveQueue May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::updateTrackBlock May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrackBlock May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPlay May 14 09:43:24 rivoplus volumio[3292]: verbose: UNSET VOLATILE: Service: airplay_emulation May 14 09:43:24 rivoplus volumio[3292]: info: Stopping Airplay Playback and sending pause command to client via USR2 May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::play index 0 May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::stop May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::stPlaybackTimer May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::updateTrackBlock May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrackBlock May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:24 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:24 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::serviceStop May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::serviceStop May 14 09:43:24 rivoplus volumio[3292]: info: [1747205004661] ControllerTidal::stop May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService mpd May 14 09:43:24 rivoplus volumio[3292]: info: ControllerMpd::stop May 14 09:43:24 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand stop May 14 09:43:24 rivoplus sudo[5081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 May 14 09:43:24 rivoplus volumio[3292]: info: sendMpdCommand stop took 37 milliseconds May 14 09:43:24 rivoplus sudo[5081]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::play index undefined May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::startPlaybackTimer May 14 09:43:24 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:24 rivoplus volumio[3292]: info: [1747205004707] ControllerTidal::clearAddPlayTrack May 14 09:43:24 rivoplus volumio[3292]: info: Getting stream with soundQuality HI_RES May 14 09:43:24 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand stop May 14 09:43:24 rivoplus volumio[3292]: info: sendMpdCommand stop took 2 milliseconds May 14 09:43:24 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clear May 14 09:43:24 rivoplus sudo[5081]: pam_unix(sudo:session): session closed for user root May 14 09:43:24 rivoplus volumio[3292]: info: May 14 09:43:24 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:24 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:24 rivoplus volumio[3292]: info: sendMpdCommand clear took 7 milliseconds May 14 09:43:24 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/77666301&soundQuality=HI_RES" May 14 09:43:24 rivoplus volumio[3292]: info: May 14 09:43:24 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:24 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:24 rivoplus volumio[3292]: error: updateQueue error: null May 14 09:43:24 rivoplus volumio[3292]: info: May 14 09:43:24 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:24 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:24 rivoplus volumio[3292]: info: ------------------------------ 17ms May 14 09:43:24 rivoplus volumio[3292]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/77666301&soundQuality=HI_RES" took 13 milliseconds May 14 09:43:24 rivoplus volumio[3292]: info: ------------------------------ 12ms May 14 09:43:24 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService mpd May 14 09:43:24 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand play May 14 09:43:24 rivoplus volumio[3292]: info: May 14 09:43:24 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:24 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:24 rivoplus volumio[3292]: info: Cannot execute Shairport-sync USR2 kill: Error: Command failed: /usr/bin/sudo /bin/kill -USR2 $(pidof shairport-sync) May 14 09:43:24 rivoplus volumio[3292]: Usage: May 14 09:43:24 rivoplus volumio[3292]: kill [options] [...] May 14 09:43:24 rivoplus volumio[3292]: Options: May 14 09:43:24 rivoplus volumio[3292]: [...] send signal to every listed May 14 09:43:24 rivoplus volumio[3292]: -, -s, --signal May 14 09:43:24 rivoplus volumio[3292]: specify the to be sent May 14 09:43:24 rivoplus volumio[3292]: -l, --list=[] list all signal names, or convert one to a name May 14 09:43:24 rivoplus volumio[3292]: -L, --table list all signal names in a nice table May 14 09:43:24 rivoplus volumio[3292]: -h, --help display this help and exit May 14 09:43:24 rivoplus volumio[3292]: -V, --version output version information and exit May 14 09:43:24 rivoplus volumio[3292]: For more details see kill(1). May 14 09:43:24 rivoplus volumio[3292]: info: ------------------------------ 18ms May 14 09:43:24 rivoplus volumio[3292]: info: sendMpdCommand play took 12 milliseconds May 14 09:43:24 rivoplus volumio[3292]: info: ------------------------------ 12ms May 14 09:43:24 rivoplus volumio[3292]: info: MCU Signalled Playback Inactive May 14 09:43:24 rivoplus volumio[3292]: STREAMING PROXY: Handling url /?data=tidal://song/77666301&soundQuality=HI_RES May 14 09:43:24 rivoplus volumio[3292]: info: Executing endpoint getStreamUrltidal May 14 09:43:24 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 14 09:43:25 rivoplus volumio[3292]: info: getStreamUrl took 345 milliseconds May 14 09:43:25 rivoplus volumio[3292]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEicwMDFlZWUyMTkyMTFjZTk2ZmMxZGY0YzA4ZTQ4Yzk2MV82Mi5tcDQ/0.flac?Expires=1747208605&Signature=mCj9dqqb-B-Qpq2UOvoaTBJPilHSRm6Jl8k1zirht7T4lqp3GWwN3U18gHNMJlBkzjECntT3PdMDskcNC6efwpHpQ6DGCkCqfPE0ONnMjcjrNj~Iy40ScfGl66vmnHtZnEd1pjK0YreyhgCQWVVbeP9HI7BehMXl7r~hBY87LWbj8gQiEbV3C1S-oHmGS9t94cbodK3J3S9Q5nNDFHBLYp1YUD54cMTpN1kaFcjmRxiXDPXTZ0T2z7kdwDFx4E272K2b-VJ4jb96BRPPsYWMKkZkjBYu5LrWpn27TFfIEY4NscIeDgnzUkgoAbfQhbGXkWCjtRn4kn~eivsoj5GfzA__&Key-Pair-Id=K14LZCZ9QUI4JL May 14 09:43:25 rivoplus volumio[3292]: STREAMING PROXY: Response: 200, length: 162983377 May 14 09:43:25 rivoplus volumio[3292]: info: May 14 09:43:25 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:25 rivoplus volumio[3292]: info: May 14 09:43:25 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:25 rivoplus volumio[3292]: info: May 14 09:43:25 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clearerror May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand status took 14 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clearerror May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand status took 16 milliseconds May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:25 rivoplus volumio[3292]: info: May 14 09:43:25 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand clearerror took 18 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand status took 17 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand clearerror took 15 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 9 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 8 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand status took 5 milliseconds May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:25 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:25 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":442,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"77666301&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/77666301&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:25 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:25 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:25 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":442,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"77666301&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/77666301&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:25 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:25 rivoplus volumio[3292]: info: ------------------------------ 100ms May 14 09:43:25 rivoplus volumio[3292]: info: ------------------------------ 97ms May 14 09:43:25 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 82 milliseconds May 14 09:43:25 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 78 milliseconds May 14 09:43:25 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:25 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:25 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":442,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"77666301&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/77666301&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:25 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:25 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:25 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:25 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":442,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"77666301&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/77666301&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:25 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:25 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:25 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:25 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:25 rivoplus volumio[3292]: info: ------------------------------ 161ms May 14 09:43:25 rivoplus volumio[3292]: info: ------------------------------ 139ms May 14 09:43:25 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:43:25 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::getUIConfigOnPlugin May 14 09:43:42 rivoplus volumio[3292]: No protocol specified May 14 09:43:42 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 14 09:43:42 rivoplus volumio[3292]: Invalid card number. May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:43:42 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:43:54 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:54 rivoplus volumio[3292]: info: CoreCommandRouter::volumioReplaceandPlayItems May 14 09:43:54 rivoplus volumio[3292]: info: CoreStateMachine::ClearQueue May 14 09:43:54 rivoplus volumio[3292]: info: CoreStateMachine::stop May 14 09:43:54 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:54 rivoplus volumio[3292]: info: CorePlayQueue::clearPlayQueue May 14 09:43:54 rivoplus volumio[3292]: info: CorePlayQueue::saveQueue May 14 09:43:54 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushQueue May 14 09:43:54 rivoplus volumio[3292]: info: CoreStateMachine::addQueueItems May 14 09:43:54 rivoplus volumio[3292]: info: CorePlayQueue::addQueueItems May 14 09:43:54 rivoplus volumio[3292]: info: Preload queue cleared May 14 09:43:54 rivoplus volumio[3292]: info: Adding Item to queue: tidal://mymusic/mixes/0027e2234d792a68d9ebc8504f12aa May 14 09:43:54 rivoplus volumio[3292]: info: Exploding uri tidal://mymusic/mixes/0027e2234d792a68d9ebc8504f12aa in service tidal May 14 09:43:55 rivoplus volumio[3292]: info: explodeTIDALUri took 1047 milliseconds May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushQueue May 14 09:43:55 rivoplus volumio[3292]: info: CorePlayQueue::saveQueue May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::updateTrackBlock May 14 09:43:55 rivoplus volumio[3292]: info: CorePlayQueue::getTrackBlock May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPlay May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::play index 0 May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::stop May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::play index undefined May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 09:43:55 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::startPlaybackTimer May 14 09:43:55 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:55 rivoplus volumio[3292]: info: [1747205035394] ControllerTidal::clearAddPlayTrack May 14 09:43:55 rivoplus volumio[3292]: info: Getting stream with soundQuality HI_RES May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand stop May 14 09:43:55 rivoplus volumio[3292]: info: May 14 09:43:55 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:55 rivoplus volumio[3292]: STREAMING PROXY: Client dropped request, destroying May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand stop took 11 milliseconds May 14 09:43:55 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clear May 14 09:43:55 rivoplus volumio[3292]: info: May 14 09:43:55 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:55 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand status took 4 milliseconds May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand clear took 3 milliseconds May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/376694339&soundQuality=HI_RES" May 14 09:43:55 rivoplus volumio[3292]: info: May 14 09:43:55 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:55 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:55 rivoplus volumio[3292]: error: updateQueue error: null May 14 09:43:55 rivoplus volumio[3292]: info: May 14 09:43:55 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:55 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:55 rivoplus volumio[3292]: info: ------------------------------ 11ms May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 7 milliseconds May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/376694339&soundQuality=HI_RES" took 7 milliseconds May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand status took 8 milliseconds May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::setConsumeUpdateService mpd May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand play May 14 09:43:55 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:55 rivoplus volumio[3292]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 14 09:43:55 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:55 rivoplus volumio[3292]: STREAMING PROXY: Handling url /?data=tidal://song/376694339&soundQuality=HI_RES May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:55 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:55 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:55 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:55 rivoplus volumio[3292]: 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} May 14 09:43:55 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService stop May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:55 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:55 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:55 rivoplus volumio[3292]: info: No code May 14 09:43:55 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:55 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:55 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:55 rivoplus volumio[3292]: info: ------------------------------ 55ms May 14 09:43:55 rivoplus volumio[3292]: info: ------------------------------ 64ms May 14 09:43:55 rivoplus volumio[3292]: info: May 14 09:43:55 rivoplus volumio[3292]: ---------------------------- MPD announces system playlist update May 14 09:43:55 rivoplus volumio[3292]: info: Ignoring MPD Status Update May 14 09:43:55 rivoplus volumio[3292]: info: ------------------------------ 69ms May 14 09:43:55 rivoplus volumio[3292]: info: sendMpdCommand play took 61 milliseconds May 14 09:43:55 rivoplus volumio[3292]: info: ------------------------------ 9ms May 14 09:43:55 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:43:55 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:43:55 rivoplus volumio[3292]: info: Executing endpoint getStreamUrltidal May 14 09:43:55 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 14 09:43:55 rivoplus volumio[3292]: info: getStreamUrl took 364 milliseconds May 14 09:43:55 rivoplus volumio[3292]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiRmNzY2YzIzM2Y3M2E4Mjk0MmZmNzBlN2RjMjhlOGY5NS5tcDQ/0.flac?Expires=1747208635&Signature=jyeZt0ogUfVru4ZBDfFW1uF45Y3eU4wqbbtYPQIq~MEsIoSe-t32jUyyJ6ZEDKb-lcARwNastwXIly82rFlYztwIVxAGhgEkvYJ-UtHAQRhx62DxfPo-Ca8oVjHQ37V9nr6ZRhRYMFN5kBZx-V2YLhIF~jc15PUCrbzcC9JMnb61iqWONtdb3EGLETVxip2ZnYzDnpa8xnTxqABx~pvJeVkGA2dvE-D5sbFAwTaLjQVrqVIaHyr-b3uUS4966RZxeJ6wzxBut7BrGbynv0wppQkKD3nEGjx8FoBVSh5GX-cfJHP6q8lHOaakytXa1CCiQbhxafg4Dbf58xjsNGmqTg__&Key-Pair-Id=K14LZCZ9QUI4JL May 14 09:43:56 rivoplus volumio[3292]: STREAMING PROXY: Response: 200, length: 68034133 May 14 09:43:56 rivoplus volumio[3292]: info: May 14 09:43:56 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:56 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:56 rivoplus volumio[3292]: info: May 14 09:43:56 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:56 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:56 rivoplus volumio[3292]: info: May 14 09:43:56 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:56 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clearerror May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand status took 11 milliseconds May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clearerror May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand status took 11 milliseconds May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:56 rivoplus volumio[3292]: info: May 14 09:43:56 rivoplus volumio[3292]: ---------------------------- MPD announces state update: player May 14 09:43:56 rivoplus volumio[3292]: info: ControllerMpd::getState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand status May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand clearerror May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand status took 34 milliseconds May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand clearerror took 29 milliseconds May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand clearerror took 27 milliseconds May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 16 milliseconds May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 15 milliseconds May 14 09:43:56 rivoplus volumio[3292]: info: sendMpdCommand status took 12 milliseconds May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::parseState May 14 09:43:56 rivoplus volumio[3292]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 09:43:56 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:56 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:56 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":236,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"376694339&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/376694339&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:56 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:56 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:56 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:56 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:56 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:56 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:56 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:56 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:56 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":236,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"376694339&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/376694339&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:56 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:56 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:56 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:56 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:56 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:56 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:56 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:56 rivoplus volumio[3292]: info: ------------------------------ 119ms May 14 09:43:56 rivoplus volumio[3292]: info: ------------------------------ 119ms May 14 09:43:57 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:43:57 rivoplus volumio[3292]: info: sendMpdCommand clearerror took 137 milliseconds May 14 09:43:57 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 134 milliseconds May 14 09:43:57 rivoplus volumio[3292]: info: sendMpdCommand playlistinfo took 132 milliseconds May 14 09:43:57 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:57 rivoplus volumio[3292]: verbose: ControllerMpd::parseTrackInfo May 14 09:43:57 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:57 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:57 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":236,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"376694339&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/376694339&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:57 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:57 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:57 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:57 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:57 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:57 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:57 rivoplus volumio[3292]: info: ControllerMpd::pushState May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::servicePushState May 14 09:43:57 rivoplus volumio[3292]: info: CorePlayQueue::getTrack 0 May 14 09:43:57 rivoplus volumio[3292]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":236,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"376694339&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/376694339&soundQuality=HI_RES","trackType":"tidal"} May 14 09:43:57 rivoplus volumio[3292]: verbose: CURRENT POSITION 0 May 14 09:43:57 rivoplus volumio[3292]: info: CoreStateMachine::syncState stateService pause May 14 09:43:57 rivoplus volumio[3292]: info: CoreStateMachine::syncState currentStatus stop May 14 09:43:57 rivoplus volumio[3292]: info: CoreStateMachine::pushState May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::volumioPushState May 14 09:43:57 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:43:57 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output update for this device May 14 09:43:57 rivoplus volumio[3292]: info: MRS: Pushing multiroomSync output May 14 09:43:57 rivoplus volumio[3292]: info: ------------------------------ 306ms May 14 09:43:57 rivoplus volumio[3292]: info: ------------------------------ 283ms May 14 09:43:57 rivoplus volumio[3292]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 14 09:44:00 rivoplus volumio[3292]: STREAMING PROXY: Client dropped request, destroying May 14 09:44:02 rivoplus sudo[5213]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 14 09:44:02 rivoplus sudo[5213]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:02 rivoplus sudo[5213]: pam_unix(sudo:session): session closed for user root May 14 09:44:02 rivoplus sudo[5216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 14 09:44:02 rivoplus sudo[5216]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:02 rivoplus sudo[5216]: pam_unix(sudo:session): session closed for user root May 14 09:44:02 rivoplus volumio[3292]: verbose: New Socket.io Connection to 192.168.0.103 from 192.168.0.251 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.4 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 6 May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetVisibleSources May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetQueue May 14 09:44:02 rivoplus volumio[3292]: info: CoreStateMachine::getQueue May 14 09:44:02 rivoplus volumio[3292]: info: CorePlayQueue::getQueue May 14 09:44:02 rivoplus volumio[3292]: info: Listing playlists May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 14 09:44:02 rivoplus volumio[3292]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 14 09:44:02 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 14 09:44:04 rivoplus volumio[3292]: info: Received Get System Info May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 14 09:44:04 rivoplus volumio[3292]: info: Discovery: Getting this device information May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 09:44:04 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 14 09:44:05 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 14 09:44:05 rivoplus volumio[3292]: info: Received Get System Info May 14 09:44:05 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 14 09:44:05 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 14 09:44:05 rivoplus volumio[3292]: info: Discovery: Getting this device information May 14 09:44:05 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:05 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 09:44:08 rivoplus kernel: CFG80211-ERROR) wl_cfg80211_disconnect : Reason 3 May 14 09:44:08 rivoplus kernel: dhd_dbg_stop_pkt_monitor, 1963 May 14 09:44:08 rivoplus kernel: wl_iw_event: Link Down with 10:3c:59:bb:35:54, reason=2 May 14 09:44:08 rivoplus kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_LINK May 14 09:44:08 rivoplus kernel: link down if wlan0 may call cfg80211_disconnected. event : 16, reason=2 from 10:3c:59:bb:35:54 May 14 09:44:08 rivoplus kernel: dhd_dbg_stop_pkt_monitor, 1963 May 14 09:44:08 rivoplus kernel: CFG80211-ERROR) wl_cfg80211_tdls_config : No change in tdls state. Do nothing. tdls_enable:1 May 14 09:44:08 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-DISCONNECTED bssid=10:3c:59:bb:35:54 reason=0 May 14 09:44:08 rivoplus dhcpcd[3259]: wlan0: carrier lost May 14 09:44:08 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD May 14 09:44:08 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=BG May 14 09:44:08 rivoplus avahi-daemon[2824]: Withdrawing address record for 192.168.0.103 on wlan0. May 14 09:44:08 rivoplus avahi-daemon[2824]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.103. May 14 09:44:08 rivoplus avahi-daemon[2824]: Interface wlan0.IPv4 no longer relevant for mDNS. May 14 09:44:08 rivoplus volumio[3292]: info: Discovery: A device disappeared from network May 14 09:44:08 rivoplus volumio[3292]: info: Discovery: Device rivoplus disappeared from network May 14 09:44:08 rivoplus dhcpcd[3259]: wlan0: deleting route to 192.168.0.0/24 May 14 09:44:08 rivoplus dhcpcd[3259]: wlan0: deleting default route via 192.168.0.1 May 14 09:44:08 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD May 14 09:44:08 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=BG May 14 09:44:10 rivoplus ntpd[5030]: Deleting interface #3 wlan0, 192.168.0.103#123, interface stats: received=67, sent=79, dropped=0, active_time=58 secs May 14 09:44:10 rivoplus ntpd[5030]: 84.54.128.102 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 77.236.182.128 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 162.159.200.1 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 194.59.28.22 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 78.159.131.45 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 185.117.82.66 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 176.12.60.87 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 185.117.82.71 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 162.159.200.123 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 195.85.215.215 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 213.91.190.163 local addr 192.168.0.103 -> May 14 09:44:10 rivoplus ntpd[5030]: 213.91.190.205 local addr 192.168.0.103 -> May 14 09:44:12 rivoplus wpa_supplicant[3173]: wlan0: Trying to associate with 10:3c:59:bb:35:54 (SSID='A1Home' freq=5745 MHz) May 14 09:44:12 rivoplus kernel: Connecting with 10:3c:59:bb:35:54 ssid "A1Home", len (6) channel=149 May 14 09:44:12 rivoplus kernel: dhd_dbg_start_pkt_monitor, 1724 May 14 09:44:12 rivoplus kernel: wl_iw_event: Link UP with 10:3c:59:bb:35:54 May 14 09:44:12 rivoplus kernel: wl_bss_connect_done succeeded with 10:3c:59:bb:35:54 May 14 09:44:12 rivoplus kernel: CFG80211-ERROR) wl_cfg80211_scan_abort : scan abort failed May 14 09:44:12 rivoplus wpa_supplicant[3173]: wlan0: Associated with 10:3c:59:bb:35:54 May 14 09:44:12 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 14 09:44:12 rivoplus kernel: wl_bss_connect_done succeeded with 10:3c:59:bb:35:54 vndr_oui: 8C-FD-F0 May 14 09:44:12 rivoplus wpa_supplicant[3173]: wlan0: WPA: Key negotiation completed with 10:3c:59:bb:35:54 [PTK=CCMP GTK=CCMP] May 14 09:44:12 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-CONNECTED - Connection to 10:3c:59:bb:35:54 completed [id=0 id_str=] May 14 09:44:12 rivoplus dhcpcd[3259]: wlan0: carrier acquired May 14 09:44:12 rivoplus wpa_supplicant[3173]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=AT May 14 09:44:12 rivoplus dhcpcd[3259]: wlan0: IAID c9:8f:f5:84 May 14 09:44:13 rivoplus dhcpcd[3259]: wlan0: rebinding lease of 192.168.0.103 May 14 09:44:13 rivoplus dhcpcd[3259]: wlan0: probing address 192.168.0.103/24 May 14 09:44:13 rivoplus dhcpcd[3259]: wlan0: soliciting an IPv6 router May 14 09:44:17 rivoplus nmbd[3067]: [2025/05/14 09:44:17.025333, 0] ../source3/nmbd/nmbd.c:361(reload_interfaces) May 14 09:44:17 rivoplus nmbd[3067]: reload_interfaces: No subnets to listen to. Waiting.. May 14 09:44:17 rivoplus volumio[3292]: info: Reporting MCU Network Status: 0 May 14 09:44:17 rivoplus volumio[3292]: info: Volumio Network Manager: Network status updated: 0 May 14 09:44:18 rivoplus dhcpcd[3259]: wlan0: leased 192.168.0.103 for 86400 seconds May 14 09:44:18 rivoplus avahi-daemon[2824]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.103. May 14 09:44:18 rivoplus dhcpcd[3259]: wlan0: adding route to 192.168.0.0/24 May 14 09:44:18 rivoplus dhcpcd[3259]: wlan0: adding default route via 192.168.0.1 May 14 09:44:18 rivoplus avahi-daemon[2824]: New relevant interface wlan0.IPv4 for mDNS. May 14 09:44:18 rivoplus avahi-daemon[2824]: Registering new address record for 192.168.0.103 on wlan0.IPv4. May 14 09:44:18 rivoplus ntpd[5030]: ntpd exiting on signal 15 (Terminated) May 14 09:44:18 rivoplus systemd[1]: Stopping Network Time Service... May 14 09:44:18 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:18 rivoplus systemd[1]: ntp.service: Succeeded. May 14 09:44:18 rivoplus systemd[1]: Stopped Network Time Service. May 14 09:44:18 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:18 rivoplus systemd[1]: Starting Network Time Service... May 14 09:44:18 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:18 rivoplus ntpd[5323]: ntpd 4.2.8p12@1.3728-o (1): Starting May 14 09:44:18 rivoplus ntpd[5323]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 May 14 09:44:18 rivoplus systemd[1]: Started Network Time Service. May 14 09:44:18 rivoplus ntpd[5336]: proto: precision = 1.250 usec (-20) May 14 09:44:18 rivoplus ntpd[5336]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature May 14 09:44:18 rivoplus ntpd[5336]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 May 14 09:44:18 rivoplus ntpd[5336]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 869 days ago May 14 09:44:18 rivoplus ntpd[5336]: Listen and drop on 0 v6wildcard [::]:123 May 14 09:44:18 rivoplus ntpd[5336]: Listen and drop on 1 v4wildcard 0.0.0.0:123 May 14 09:44:18 rivoplus ntpd[5336]: Listen normally on 2 lo 127.0.0.1:123 May 14 09:44:18 rivoplus ntpd[5336]: Listen normally on 3 wlan0 192.168.0.103:123 May 14 09:44:18 rivoplus ntpd[5336]: Listening on routing socket on fd #20 for interface updates May 14 09:44:18 rivoplus ntpd[5336]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 14 09:44:18 rivoplus ntpd[5336]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 14 09:44:18 rivoplus volumio[3292]: info: MRS: Found cast device: B866V2F02-673d153d0fe5139ea03d0914ec9983f9 May 14 09:44:19 rivoplus volumio[3292]: info: Discovery: adding 5e2a4850-80a7-4a92-950e-09eb5e5fea18 May 14 09:44:19 rivoplus volumio[3292]: info: Discovery: Found device Rivoplus May 14 09:44:19 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:19 rivoplus volumio[3292]: info: Enabling plugin fusiondsp May 14 09:44:19 rivoplus volumio[3292]: info: CoreCommandRouter::getUIConfigOnPlugin May 14 09:44:19 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 14 09:44:19 rivoplus volumio[3292]: info: Loading plugin "fusiondsp"... May 14 09:44:19 rivoplus ntpd[5336]: Soliciting pool server 213.91.190.163 May 14 09:44:20 rivoplus volumio[3292]: info: Applying required configuration parameters for plugin fusiondsp May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 14 09:44:20 rivoplus volumio[3292]: info: Preparing to generate the ALSA configuration file May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 14 09:44:20 rivoplus volumio[3292]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 14 09:44:20 rivoplus volumio[3292]: info: Received Get System Version May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 14 09:44:20 rivoplus volumio[3292]: info: Received Get System Info May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 14 09:44:20 rivoplus volumio[3292]: info: Discovery: Getting this device information May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 09:44:20 rivoplus volumio[3292]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 14 09:44:20 rivoplus volumio[3292]: info: Reading ALSA contributions from plugins. May 14 09:44:20 rivoplus volumio[3292]: info: Asound.conf file unchanged, so no further update is needed May 14 09:44:20 rivoplus volumio[3292]: info: Output device has changed, restarting MPD May 14 09:44:20 rivoplus volumio[3292]: info: Output device has changed, restarting Shairport Sync May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 14 09:44:20 rivoplus sudo[5368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 14 09:44:20 rivoplus sudo[5368]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:20 rivoplus sudo[5368]: pam_unix(sudo:session): session closed for user root May 14 09:44:20 rivoplus sudo[5370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 14 09:44:20 rivoplus sudo[5370]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:20 rivoplus systemd[1]: Stopping Music Player Daemon... May 14 09:44:20 rivoplus volumio[3292]: No protocol specified May 14 09:44:20 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:20 rivoplus volumio[3292]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 14 09:44:20 rivoplus volumio[3292]: No protocol specified May 14 09:44:20 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:20 rivoplus volumio[3292]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: info: QobuzConnect: setDeactiveState invoked May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:20 rivoplus volumio[3292]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus vtcs[4207]: [2025-05-14 09:44:20.604] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 14 09:44:20 rivoplus vtcs[4207]: [2025-05-14 09:44:20.604] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 14 09:44:20 rivoplus ntpd[5336]: Soliciting pool server 213.91.190.205 May 14 09:44:20 rivoplus volumio[3292]: info: PLUGIN START: fusiondsp May 14 09:44:20 rivoplus systemd[1]: mpd.service: Succeeded. May 14 09:44:20 rivoplus volumio[3292]: info: Loading i18n strings for locale en May 14 09:44:20 rivoplus systemd[1]: Stopped Music Player Daemon. May 14 09:44:20 rivoplus systemd[1]: Starting Music Player Daemon... May 14 09:44:20 rivoplus sudo[5379]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 14 09:44:20 rivoplus sudo[5379]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: info: FusionDsp - mixtype--------------------- None May 14 09:44:20 rivoplus volumio[3292]: info: Preparing to generate the ALSA configuration file May 14 09:44:20 rivoplus ntpd[5336]: Soliciting pool server 195.85.215.8 May 14 09:44:20 rivoplus systemd[1]: Stopping Volumio Tidal Connect Service... May 14 09:44:20 rivoplus systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 14 09:44:20 rivoplus systemd[1]: vtcs.service: Succeeded. May 14 09:44:20 rivoplus systemd[1]: Stopped Volumio Tidal Connect Service. May 14 09:44:20 rivoplus volumio[3292]: info: Done. May 14 09:44:20 rivoplus sudo[5379]: pam_unix(sudo:session): session closed for user root May 14 09:44:20 rivoplus sudo[5384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 14 09:44:20 rivoplus sudo[5384]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: info: QobuzConnect: Setting Qobuz Connect card as outputdevice to 5 May 14 09:44:20 rivoplus sudo[5384]: pam_unix(sudo:session): session closed for user root May 14 09:44:20 rivoplus volumio[3292]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 14 09:44:20 rivoplus volumio[3292]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 14 09:44:20 rivoplus volumio[3292]: info: Reading ALSA contributions from plugins. May 14 09:44:20 rivoplus sudo[5380]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 14 09:44:20 rivoplus sudo[5380]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:20 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:20 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:20 rivoplus sudo[5380]: pam_unix(sudo:session): session closed for user root May 14 09:44:20 rivoplus sudo[5391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect May 14 09:44:20 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:20 rivoplus sudo[5391]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:20 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:20 rivoplus volumio[3292]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 14 09:44:20 rivoplus volumio[3292]: info: MPD Permissions set May 14 09:44:20 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 14 09:44:20 rivoplus qobuz-connect[4157]: 20250514 09:44:20.871 [4157.4157] INFO SampleApp: Stopping Local configuration server May 14 09:44:20 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:20 rivoplus qobuz-connect[4157]: 20250514 09:44:20.882 [4157.4157] INFO SampleApp: shat down connection on UNIX socket May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 14 09:44:20 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 14 09:44:20 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. May 14 09:44:20 rivoplus sudo[5391]: pam_unix(sudo:session): session closed for user root May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:20 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:20 rivoplus volumio[3292]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 14 09:44:20 rivoplus volumio[3292]: info: QobuzConnect: setDeactiveState invoked May 14 09:44:20 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:21 rivoplus volumio[3292]: info: Starting Shairport Sync May 14 09:44:21 rivoplus volumio[3292]: info: Executing endpoint qc_getconfig May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.049 [5395.5395] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.056 [5395.5395] INFO VolumeManager: [0xab7777a0]: Setting new playback volume: 75 May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.056 [5395.5395] INFO VolumeManager: [0xab7777a0]: Setting new mute state: 0 May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.056 [5395.5395] INFO QobuzConnect: [0xab778170]: Client initialized! May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.056 [5395.5395] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: QOBUZ Connect daemon connected May 14 09:44:21 rivoplus sudo[5405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 14 09:44:21 rivoplus volumio[3292]: info: Asound.conf file written May 14 09:44:21 rivoplus sudo[5405]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.075 [5395.5395] INFO LocalConfigManager: [0xab777080]: Starting Local Configuration server May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.075 [5395.5395] INFO SampleApp: Starting Local configuration server May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.076 [5395.5395] INFO SampleApp: Connected to UNIX socket client 0xab76ced8 May 14 09:44:21 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 14 09:44:21 rivoplus sudo[5405]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus sudo[5409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 14 09:44:21 rivoplus sudo[5409]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus sudo[5409]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.199 [5395.5395] INFO SampleApp: Playback volume changed: 75 May 14 09:44:21 rivoplus kernel: Fine tdm clk setting range (0~2000000), 12287994 May 14 09:44:21 rivoplus kernel: Err: can not set rate to 4274967296! May 14 09:44:21 rivoplus kernel: Range[3920000 - 500000000] May 14 09:44:21 rivoplus kernel: out of value, fixed it May 14 09:44:21 rivoplus kernel: id=0 set inskew=0 May 14 09:44:21 rivoplus volumio[3292]: No protocol specified May 14 09:44:21 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:21 rivoplus volumio[3292]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted May 14 09:44:21 rivoplus volumio[3292]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted May 14 09:44:21 rivoplus volumio[3292]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted May 14 09:44:21 rivoplus volumio[3292]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted May 14 09:44:21 rivoplus volumio[3292]: info: Output device has changed, restarting MPD May 14 09:44:21 rivoplus sudo[5417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 14 09:44:21 rivoplus sudo[5417]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus volumio[3292]: info: Output device has changed, restarting Shairport Sync May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 14 09:44:21 rivoplus sudo[5417]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus sudo[5419]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 14 09:44:21 rivoplus sudo[5419]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 14 09:44:21 rivoplus systemd[1]: mpd.service: Succeeded. May 14 09:44:21 rivoplus systemd[1]: Stopped Music Player Daemon. May 14 09:44:21 rivoplus volumio[3292]: No protocol specified May 14 09:44:21 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:21 rivoplus volumio[3292]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 14 09:44:21 rivoplus volumio[3292]: No protocol specified May 14 09:44:21 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:21 rivoplus volumio[3292]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus systemd[1]: Starting Music Player Daemon... May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: setDeactiveState invoked May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:21 rivoplus volumio[3292]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus sudo[5430]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 14 09:44:21 rivoplus sudo[5430]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus sudo[5430]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus sudo[5434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 14 09:44:21 rivoplus sudo[5434]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: Setting Qobuz Connect card as outputdevice to 5 May 14 09:44:21 rivoplus sudo[5426]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 14 09:44:21 rivoplus sudo[5426]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus sudo[5426]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus sudo[5434]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:21 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:21 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:21 rivoplus sudo[5443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect May 14 09:44:21 rivoplus sudo[5443]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:21 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.611 [5395.5395] INFO SampleApp: Stopping Local configuration server May 14 09:44:21 rivoplus ntpd[5336]: Soliciting pool server 185.117.82.71 May 14 09:44:21 rivoplus systemd[1]: Stopping Volumio Qobuz Connect Service... May 14 09:44:21 rivoplus ntpd[5336]: Soliciting pool server 162.159.200.123 May 14 09:44:21 rivoplus qobuz-connect[5395]: 20250514 09:44:21.621 [5395.5395] INFO SampleApp: shat down connection on UNIX socket May 14 09:44:21 rivoplus ntpd[5336]: Soliciting pool server 176.12.60.87 May 14 09:44:21 rivoplus systemd[1]: qobuz-connect.service: Succeeded. May 14 09:44:21 rivoplus systemd[1]: Stopped Volumio Qobuz Connect Service. May 14 09:44:21 rivoplus systemd[1]: Started Volumio Qobuz Connect Service. May 14 09:44:21 rivoplus sudo[5443]: pam_unix(sudo:session): session closed for user root May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: Not Reporting Auto name since its the default one May 14 09:44:21 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:21 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:21 rivoplus volumio[3292]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 14 09:44:21 rivoplus volumio[3292]: info: MPD Permissions set May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: setDeactiveState invoked May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:21 rivoplus volumio[3292]: info: Shairport-Sync Started May 14 09:44:21 rivoplus volumio[3292]: info: Executing endpoint qc_getconfig May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.753 [5450.5450] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.760 [5450.5450] INFO VolumeManager: [0xab0eb7a0]: Setting new playback volume: 75 May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.760 [5450.5450] INFO VolumeManager: [0xab0eb7a0]: Setting new mute state: 0 May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.760 [5450.5450] INFO QobuzConnect: [0xab0ec170]: Client initialized! May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.760 [5450.5450] INFO SampleApp: Starting Avahi advertising, name: Rivoplus, service name: _qobuz-connect._tcp May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.776 [5450.5450] INFO LocalConfigManager: [0xab0eb080]: Starting Local Configuration server May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.776 [5450.5450] INFO SampleApp: Starting Local configuration server May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.777 [5450.5450] INFO SampleApp: Connected to UNIX socket client 0xab0e0ed8 May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 14 09:44:21 rivoplus volumio[3292]: No protocol specified May 14 09:44:21 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:21 rivoplus volumio[3292]: info: Configured Audio card not found, not starting RAAT May 14 09:44:21 rivoplus qobuz-connect[5450]: 20250514 09:44:21.902 [5450.5450] INFO SampleApp: Playback volume changed: 75 May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 14 09:44:21 rivoplus volumio[3292]: info: Not Reporting Auto name since its the default one May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 14 09:44:21 rivoplus volumio[3292]: info: QobuzConnect: QOBUZ Connect daemon connected May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::volumioGetState May 14 09:44:21 rivoplus volumio[3292]: info: Starting Shairport Sync May 14 09:44:21 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 14 09:44:22 rivoplus sudo[5466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 14 09:44:22 rivoplus sudo[5466]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:22 rivoplus systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 14 09:44:22 rivoplus systemd[1]: shairport-sync.service: Succeeded. May 14 09:44:22 rivoplus systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 14 09:44:22 rivoplus volumio[3292]: No protocol specified May 14 09:44:22 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:22 rivoplus volumio[3292]: info: Configured Audio card not found, not starting RAAT May 14 09:44:22 rivoplus systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 14 09:44:22 rivoplus sudo[5466]: pam_unix(sudo:session): session closed for user root May 14 09:44:22 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: running May 14 09:44:22 rivoplus volumio[3292]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 14 09:44:22 rivoplus volumio[3292]: info: Shairport-Sync Started May 14 09:44:22 rivoplus ntpd[5336]: Soliciting pool server 185.117.82.66 May 14 09:44:22 rivoplus ntpd[5336]: Soliciting pool server 94.26.6.190 May 14 09:44:22 rivoplus ntpd[5336]: Soliciting pool server 195.85.215.215 May 14 09:44:22 rivoplus volumio[3292]: info: camilladsp spawned new process with pid undefined, instance 1, run: true May 14 09:44:22 rivoplus volumio[3292]: info: camilladsp service started and running in background, instance 1 May 14 09:44:22 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:22 rivoplus volumio[3292]: No protocol specified May 14 09:44:22 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:22 rivoplus volumio[3292]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card May 14 09:44:22 rivoplus volumio[3292]: cannot open device 'volumioHw': No such device May 14 09:44:22 rivoplus volumio[3292]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 14 09:44:22 rivoplus volumio[3292]: No protocol specified May 14 09:44:22 rivoplus volumio[3292]: xcb_connection_has_error() returned true May 14 09:44:22 rivoplus volumio[3292]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card May 14 09:44:22 rivoplus volumio[3292]: cannot open device 'volumioHw': No such device May 14 09:44:22 rivoplus volumio[3292]: info: FusionDsp loaded May 14 09:44:22 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 09:44:22 rivoplus sudo[5483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 14 09:44:22 rivoplus sudo[5483]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 09:44:22 rivoplus volumio[3292]: info: FusionDsp - Reporting Fusion DSP Enabled May 14 09:44:22 rivoplus volumio[3292]: info: Adding Signal Path Element [object Object] May 14 09:44:22 rivoplus volumio[3292]: info: Adding fusiondspeq DSP Signal Path Element May 14 09:44:22 rivoplus volumio[3292]: info: Additional DSP elements updated May 14 09:44:22 rivoplus volumio[3292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 14 09:44:22 rivoplus volumio[3292]: info: Updating RAAT Signal Path May 14 09:44:22 rivoplus volumio[3292]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 14 09:44:22 rivoplus volumio[3292]: info: FusionDsp - ---- installed callbackRead May 14 09:44:22 rivoplus volumio[3292]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 14 09:44:22 rivoplus volumio[3292]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT May 14 09:44:22 rivoplus volumio[3292]: at Process.ChildProcess._handle.onexit (internal/child_process.js:277:19) May 14 09:44:22 rivoplus volumio[3292]: at onErrorNT (internal/child_process.js:472:16) May 14 09:44:22 rivoplus volumio[3292]: at processTicksAndRejections (internal/process/task_queues.js:82:21) { May 14 09:44:22 rivoplus volumio[3292]: errno: -2, May 14 09:44:22 rivoplus volumio[3292]: code: 'ENOENT', May 14 09:44:22 rivoplus volumio[3292]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', May 14 09:44:22 rivoplus volumio[3292]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', May 14 09:44:22 rivoplus volumio[3292]: spawnargs: [ May 14 09:44:22 rivoplus volumio[3292]: '-p', May 14 09:44:22 rivoplus volumio[3292]: 9876, May 14 09:44:22 rivoplus volumio[3292]: '-o', May 14 09:44:22 rivoplus volumio[3292]: '/tmp/camilladsp.log', May 14 09:44:22 rivoplus volumio[3292]: '-l', May 14 09:44:22 rivoplus volumio[3292]: 'warn', May 14 09:44:22 rivoplus volumio[3292]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' May 14 09:44:22 rivoplus volumio[3292]: ] May 14 09:44:22 rivoplus volumio[3292]: } May 14 09:44:22 rivoplus volumio[3292]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 14 09:44:22 rivoplus systemd[1]: Started FusionDsp Daemon. May 14 09:44:22 rivoplus sudo[5483]: pam_unix(sudo:session): session closed for user root May 14 09:44:23 rivoplus volumio[5485]: /usr/bin/python3: can't open file '/data/plugins/audio_interface/fusiondsp/cgui/main.py': [Errno 2] No such file or directory May 14 09:44:23 rivoplus systemd[1]: fusiondsp.service: Main process exited, code=exited, status=2/INVALIDARGUMENT May 14 09:44:23 rivoplus systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 14 09:44:23 rivoplus mpd[5444]: May 14 09:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 14 09:44:23 rivoplus systemd[1]: Started Music Player Daemon. May 14 09:44:23 rivoplus sudo[5419]: pam_unix(sudo:session): session closed for user root May 14 09:44:23 rivoplus sudo[5370]: pam_unix(sudo:session): session closed for user root May 14 09:44:23 rivoplus ntpd[5336]: Soliciting pool server 194.59.28.22 May 14 09:44:23 rivoplus ntpd[5336]: Soliciting pool server 162.159.200.1 May 14 09:44:23 rivoplus sudo[5497]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-14 09:43 May 14 09:44:23 rivoplus sudo[5497]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:06:47 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="f92ac0ecb6de863dba28fedfed23f19e"