-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Wed 2026-05-27 18:05:45 EDT. --
May 27 18:04:12 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:12 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:18 rivoplus volumio[3183]: info: MCU Signalled Sleep Mode Active
May 27 18:04:18 rivoplus sudo[5009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force off
May 27 18:04:18 rivoplus sudo[5009]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:18 rivoplus kernel: fb: osd[0] enable: 1 (Xorg)
May 27 18:04:18 rivoplus kernel: fb: osd[0] enable: 0 (Xorg)
May 27 18:04:18 rivoplus kernel: fb: osd[0] enable: 0 (Xorg)
May 27 18:04:18 rivoplus sudo[5009]: pam_unix(sudo:session): session closed for user root
May 27 18:04:18 rivoplus volumio[3183]: info: Enabling Screen Saver via dpms
May 27 18:04:32 rivoplus volumio[3183]: info: MCU Signalled Sleep Mode Disabled
May 27 18:04:32 rivoplus sudo[5092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on
May 27 18:04:32 rivoplus sudo[5092]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:32 rivoplus kernel: fb: osd[0] enable: 1 (Xorg)
May 27 18:04:32 rivoplus kernel: fb: osd[0] enable: 1 (Xorg)
May 27 18:04:32 rivoplus sudo[5092]: pam_unix(sudo:session): session closed for user root
May 27 18:04:32 rivoplus sudo[5095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0
May 27 18:04:32 rivoplus sudo[5095]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:32 rivoplus sudo[5095]: pam_unix(sudo:session): session closed for user root
May 27 18:04:36 rivoplus volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin
May 27 18:04:36 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
May 27 18:04:36 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork
May 27 18:04:36 rivoplus sudo[5100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0
May 27 18:04:36 rivoplus sudo[5100]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:36 rivoplus sudo[5105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
May 27 18:04:36 rivoplus sudo[5105]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:36 rivoplus sudo[5100]: pam_unix(sudo:session): session closed for user root
May 27 18:04:36 rivoplus sudo[5105]: pam_unix(sudo:session): session closed for user root
May 27 18:04:36 rivoplus sudo[5112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
May 27 18:04:36 rivoplus sudo[5112]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:36 rivoplus sudo[5112]: pam_unix(sudo:session): session closed for user root
May 27 18:04:36 rivoplus sudo[5118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
May 27 18:04:36 rivoplus sudo[5118]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:36 rivoplus sudo[5118]: pam_unix(sudo:session): session closed for user root
May 27 18:04:36 rivoplus sudo[5125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 27 18:04:36 rivoplus sudo[5125]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:36 rivoplus sudo[5125]: pam_unix(sudo:session): session closed for user root
May 27 18:04:36 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache
May 27 18:04:36 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks
May 27 18:04:37 rivoplus sudo[5131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 27 18:04:37 rivoplus sudo[5131]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:37 rivoplus sudo[5131]: pam_unix(sudo:session): session closed for user root
May 27 18:04:37 rivoplus sudo[5135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
May 27 18:04:37 rivoplus sudo[5135]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:37 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:38 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:38 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:38 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:38 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:38 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:39 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:39 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:39 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:40 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:40 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 8
May 27 18:04:40 rivoplus kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04d6f3000 drv_status 0x0 e_type 69 e_states 0
May 27 18:04:41 rivoplus sudo[5135]: pam_unix(sudo:session): session closed for user root
May 27 18:04:41 rivoplus volumio[3183]: info: Received Get System Info
May 27 18:04:41 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 18:04:41 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 18:04:41 rivoplus volumio[3183]: info: Discovery: Getting this device information
May 27 18:04:41 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:41 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:41 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 18:04:41 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:41.524Z level=INFO msg="emitting wifi info changed event" component=server peer="10.110.1.112:51526,00:00:00:00:00:00%03 @ 0x238bda0" available=true connected=true macAddress=40:d9:5a:6f:43:66 ip4Address=10.110.1.31/24 ip6Address= ssid=GHomeWifi
May 27 18:04:41 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
May 27 18:04:41 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
May 27 18:04:42 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:42.542Z level=INFO msg="service successfully established" component=discovery/localnet
May 27 18:04:43 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:43.714Z level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=10.110.1.112:51526
May 27 18:04:43 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:43.715Z level=INFO msg="connection to address closed" component=conn/multi addr=10.110.1.112:51526
May 27 18:04:43 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:43.720Z level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=10.110.1.112:52211
May 27 18:04:44 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:44 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:52 rivoplus qobuz-connect[4743]: 20260527 18:04:52.936 [4743.5177] INFO SampleApp: API endpoint invoked: get-connect-info
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.5177] INFO SampleApp: API endpoint invoked: connect-to-qconnect
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.4743] INFO EndpointManager: [0xabcb0fb8]: Updating API endpoint
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.4743] INFO EndpointManager: [0xabcb0fb8]: Updating QConnect endpoint
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.4743] INFO ActiveStateManager: [0xabcb0050]: Setting new active state: active
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.4743] INFO PlaybackSessionManager: [0xabcb12d0]: Starting playback session maintenance
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.4743] INFO HttpDownloader: [0xabcb1478]: Downloading content from: https://www.qobuz.com/api.json/0.2/session/start
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.182 [4743.4743] INFO CloudClient: [0xabcb19a0]: Connecting to the cloud
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.184 [4743.4743] INFO SampleApp: Renderer is now active
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO CloudClient: [0xabcb19a0]: Connection established
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Authenticate message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Subscribe message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending JoinSession message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending VolumeChanged message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending VolumeMuted message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.424 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending MaxAudioQualityChanged message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.425 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.470 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Received SetActive message: active
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Received SetState message:
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Playing state: Playing
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Playback position: 0
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Queue version: 6.1
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Current track: TID: 70226406, QID: 241, Context UUID: 0a0711f3-e2ef-4114-8f3c-8466af51fd73
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Next track: TID: 61857530, QID: 242, Context UUID: 0a0711f3-e2ef-4114-8f3c-8466af51fd73
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO MediaEngine: [0xabcb14d8]: Stopping playback, clearing tracks
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO MediaEngine: [0xabcb14d8]: Initiating playback
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO RendererActionAvailabilityManager: [0xabcb1a10]: Renderer action 'Next' is available
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Received SetLoopMode message: Off
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO PlaybackModeManager: [0xabcb17a0]: Setting new loop mode: Off
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO MediaEngine: [0xabcb14d8]: Setting current track: 70226406, initial offset: 0ms
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Clearing all streams
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: New stream: 1
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO HttpDownloader: [0xabd8c600]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=603ca633611fff835efad87d4c549a2c&request_ts=1779919493&track_id=70226406
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO HttpDownloader: [0xabd8d4c0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=70226406
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 1]: Running audio stream
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Received SetShuffleMode message: disabled
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO PlaybackModeManager: [0xabcb17a0]: Setting new shuffle mode: disabled
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO MediaEngine: [0xabcb14d8]: Setting next track: 61857530
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: New stream: 2
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO HttpDownloader: [0xabd8e3d0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=6355e38474dd208565606db352d91887&request_ts=1779919493&track_id=61857530
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO HttpDownloader: [0xabd8f380]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=61857530
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.471 [4743.4743] INFO MediaEngine: [0xabcb14d8]: Waiting for current stream to start before starting audio renderer
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.569 [4743.4743] INFO PlaybackSessionManager: [0xabcb12d0]: Playback session has been refreshed
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.569 [4743.4743] INFO HttpDownloader: [0xabcb4ef8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=bd5826d4971ab5bc97bbf1d80eb9a1ce&request_ts=1779919493&track_id=70226406
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.569 [4743.4743] INFO HttpDownloader: [0xabd937f8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=51685d719725670a0644ca521eb0b04d&request_ts=1779919493&track_id=61857530
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.646 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 1]: Metadata became available:
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.646 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Title: Nocturne in a Minor
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.646 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Artist: Chad Lawson
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.646 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Album: The Piano
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.646 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Album art URL: https://static.qobuz.com/images/covers/4b/in/pz2mna81jin4b_600.jpg
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.650 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 2]: Metadata became available:
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.650 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Title: Separate Ways
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.650 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Artist: Teddy Thompson
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.650 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Album: Separate Ways
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.650 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: Album art URL: https://static.qobuz.com/images/covers/bc/mg/g98a0dzbrmgbc_600.jpg
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.680 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 2]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=4298472&eid=61857530&fmt=6&profile=raw&app_id=174516466&cid=2742340&etsp=1779923093&hmac=AgiEYzKXO37X10h_urw27aSFi6A
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.687 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 1]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=4298472&eid=70226406&fmt=6&profile=raw&app_id=174516466&cid=2742340&etsp=1779923093&hmac=tlMvyYuGBg8ifWAcFo4UzM3aEMc
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.781 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 1]: stream information have been fetched
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.781 [4743.4743] INFO UrlAudioSource: [0xabcbbbf0]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=4298472&eid=70226406&fmt=6&profile=raw&app_id=174516466&cid=2742340&etsp=1779923093&hmac=tlMvyYuGBg8ifWAcFo4UzM3aEMc
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.781 [4743.4743] INFO ContentFetcher: [0xabcbad38]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=4298472&eid=70226406&fmt=6&profile=raw&app_id=174516466&cid=2742340&etsp=1779923093&hmac=tlMvyYuGBg8ifWAcFo4UzM3aEMc, offset: 0
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.781 [4743.4743] INFO AudioRenderer: [0xabcb1640]: Starting audio renderer, initial playback state: Playing
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.782 [4743.4743] INFO SampleApp: [Stream 1]: New audio stream (starting from 0ms)
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.782 [4743.4743] INFO SampleApp: [Stream 1]: Stream metadata became available:
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.782 [4743.4743] INFO SampleApp: Title: Nocturne in a Minor
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.782 [4743.4743] INFO SampleApp: Artist: Chad Lawson
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.782 [4743.4743] INFO SampleApp: Album: The Piano
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.782 [4743.4743] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/4b/in/pz2mna81jin4b_600.jpg
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: QobuzConnect: setActiveState()
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: QobuzConnect: Set Qobuz connect default volume to 96
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.786 [4743.4743] INFO VolumeManager: [0xabcb1830]: Setting new playback volume: 96
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.788 [4743.4743] INFO AudioStreamManager: [0xabcb1588]: [Stream 2]: stream information have been fetched
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: QobuzConnect: Stopping currently active service
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioStop
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::stop
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::setConsumeUpdateService undefined
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::updateTrackBlock
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrackBlock
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::stPlaybackTimer
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::serviceStop
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: info: ControllerMpd::stop
May 27 18:04:53 rivoplus volumio[3183]: verbose: ControllerMpd::sendMpdCommand stop
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.803Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.804Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.807Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title=
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.807Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title=
May 27 18:04:53 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:53 rivoplus volumio[3183]: info: sendMpdCommand stop took 23 milliseconds
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::setConsumeUpdateService undefined
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:53 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:53 rivoplus volumio[3183]: verbose: STATE SERVICE {"status":"stop","service":"qobuzconnect","title":"Nocturne in a Minor","artist":"Chad Lawson","album":"The Piano","albumart":"https://static.qobuz.com/images/covers/4b/in/pz2mna81jin4b_600.jpg","uri":"","icon":"fa fa-spinner","trackType":"qobuz","codec":"","seek":26006,"duration":363,"samplerate":"44.1 kHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"stream":false,"repeatMode":"all"}
May 27 18:04:53 rivoplus volumio[3183]: verbose: CURRENT POSITION 0
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::syncState stateService stop
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::syncState currentStatus stop
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:53 rivoplus volumio[3183]: info: No code
May 27 18:04:53 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:53 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:53 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:53 rivoplus volumio[3183]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.844Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_STOPPED positionMs=26006 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.845Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=26006 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.845Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.846Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.847Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_STOPPED positionMs=26006 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.848Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=26006 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.848Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.849Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.849Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_STOPPED positionMs=26006 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.850Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=26006 volume=96
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.851Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:53 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:53.853Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:53 rivoplus volumio[3183]: info: QobuzConnect: setActiveState() completed, send playback confirmation
May 27 18:04:53 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:53 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:53 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:53 rivoplus qobuz-connect[4743]: 20260527 18:04:53.914 [4743.4743] INFO SampleApp: Initiating playback, initial state: Playing
May 27 18:04:53 rivoplus qobuz-connect[4743]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioDsp has buffer size 65536
May 27 18:04:53 rivoplus qobuz-connect[4743]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioDsp has buffer size 65536
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate from file: 44100
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - If filter freq >samplerate/2 then disable it
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate from file: 44100
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - If filter freq >samplerate/2 then disable it
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate from file: 44100
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - If filter freq >samplerate/2 then disable it
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - ---- read samplerate from file: 44100
May 27 18:04:53 rivoplus volumio[3183]: info: FusionDsp - If filter freq >samplerate/2 then disable it
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.007 [4743.4743] INFO SampleApp: Playback volume changed: 96
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.007 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Volume changed: 96
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.007 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending VolumeChanged message
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.007 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.007 [4743.4743] INFO SampleApp: Playback state changed: Playing
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.007 [4743.4743] INFO StreamingEventReporter: [0xabcb1e60]: Reporting streaming started event
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.008 [4743.4743] INFO HttpDownloader: [0xabcb1eb8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.008 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Need to send state update
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.008 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending StateUpdated message
May 27 18:04:54 rivoplus volumio[3183]: info: FusionDsp - {"Reload":{"result":"Ok"}}
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.009 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.009 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending FileAudioQualityChanged message
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.009 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.009 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending DeviceAudioQualityChanged message
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.010 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio[3183]: info: CorePlayQueue::getTrack 0
May 27 18:04:54 rivoplus volumio[3183]: verbose: STATE SERVICE {"status":"stop","service":"qobuzconnect","title":"Nocturne in a Minor","artist":"Chad Lawson","album":"The Piano","albumart":"https://static.qobuz.com/images/covers/4b/in/pz2mna81jin4b_600.jpg","uri":"","icon":"fa fa-spinner","trackType":"qobuz","codec":"","seek":0,"duration":363,"samplerate":"44.1 kHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"stream":false,"repeatMode":"all"}
May 27 18:04:54 rivoplus volumio[3183]: verbose: CURRENT POSITION 0
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::syncState stateService stop
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::syncState currentStatus stop
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio[3183]: info: No code
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.035 [4743.4743] INFO UrlAudioSource: [0xabcbbbf0]: Content info extracted
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.035 [4743.4743] INFO UrlAudioSource: [0xabcbbbf0]: Size: 20141092
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: QobuzConnect: Volume received from daemon: 96
May 27 18:04:54 rivoplus volumio[3183]: info: VolumeController::SetAlsaVolume96
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.044 [4743.5192] INFO AudioDecoder: [0xabe66058]: Stream info:
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.044 [4743.5192] INFO AudioDecoder: [0xabe66058]: Total samples: 15979788
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.044 [4743.5192] INFO AudioDecoder: [0xabe66058]: Sample rate: 44100
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.044 [4743.5192] INFO AudioDecoder: [0xabe66058]: Channel count: 2
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.044 [4743.5192] INFO AudioDecoder: [0xabe66058]: Bits per sample: 16
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.044 [4743.5192] INFO AudioDecoder: [0xabe66058]: Duration: 362353
May 27 18:04:54 rivoplus qobuz-connect[4743]: 20260527 18:04:54.045 [4743.4743] INFO UrlAudioSource: [0xabcbbbf0]: Audio properties have changed
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.130Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.130Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.131Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.132Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.133Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.132Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.134Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.134Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.135Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_STOPPED positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.135Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.136Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.140Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.141Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.142Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.145Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.145Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.147Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.148Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.149Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.148Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.150Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.151Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.152Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:04:54 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:04:54 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.186Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.188Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PLAYING positionMs=0 volume=96
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.189Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:04:54.190Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:04:54 rivoplus volumio[3183]: info: FusionDsp - {"Reload":{"result":"Ok"}}
May 27 18:04:54 rivoplus volumio[3183]: info: Signalling Playback active due to playback status change
May 27 18:04:54 rivoplus volumio[3183]: info: Signalling Playback active due to playback status change
May 27 18:04:54 rivoplus volumio[3183]: info: Signalling Playback active due to playback status change
May 27 18:04:54 rivoplus volumio[3183]: info: Signalling Playback active due to playback status change
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:04:54 rivoplus volumio[3183]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified
May 27 18:04:54 rivoplus volumio[3183]: xcb_connection_has_error() returned true
May 27 18:04:54 rivoplus volumio[3183]: info: MCU Signalled Playback Active
May 27 18:04:56 rivoplus volumio[3183]: info: Executing endpoint metavolumio
May 27 18:04:56 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
May 27 18:04:56 rivoplus volumio[3183]: info: Executing endpoint metavolumio
May 27 18:04:56 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
May 27 18:04:56 rivoplus volumio[3183]: info: Executing endpoint metavolumio
May 27 18:04:56 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
May 27 18:05:04 rivoplus qobuz-connect[4743]: 20260527 18:05:04.008 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Need to send state update
May 27 18:05:04 rivoplus qobuz-connect[4743]: 20260527 18:05:04.008 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending StateUpdated message
May 27 18:05:04 rivoplus qobuz-connect[4743]: 20260527 18:05:04.008 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:05:04 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:04 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:05:04 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:05:04 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 18:05:04 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:05:04 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:04 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:05:04 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:05:04 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:04.020Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PLAYING positionMs=5933 volume=96
May 27 18:05:04 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:04.021Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PLAYING positionMs=5933 volume=96
May 27 18:05:04 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:04.023Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:05:04 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:04.024Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:05:04 rivoplus volumio[3183]: info: Signalling Playback active due to playback status change
May 27 18:05:04 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Received SetState message:
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Playing state: Paused
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Playback position:
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Queue version:
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Current track:
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Next track:
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO MediaEngine: [0xabcb14d8]: Pausing playback
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO AudioRenderer: [0xabcb1640]: Pausing audio renderer
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO SampleApp: Pausing playback
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO SampleApp: Playback state changed: Paused
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.293 [4743.4743] INFO StreamingEventReporter: [0xabcb1e60]: Reporting streaming ended event
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.294 [4743.4743] INFO HttpDownloader: [0xabcb1eb8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.294 [4743.4743] INFO ProtocolHandler: [0xabcb1ab0]: Need to send state update
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.294 [4743.4743] INFO QConnectMessageSender: [0xabe3c0b8]: Sending StateUpdated message
May 27 18:05:08 rivoplus qobuz-connect[4743]: 20260527 18:05:08.294 [4743.4743] INFO QwspMessageSender: [0xabe3c0a8]: Sending Payload message
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:08 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:05:08 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:08 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:05:08 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::servicePushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreStateMachine::pushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioPushState
May 27 18:05:08 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:08 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output update for this device
May 27 18:05:08 rivoplus volumio[3183]: info: MRS: Pushing multiroomSync output
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.317Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PAUSED positionMs=5933 volume=96
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.318Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PAUSED positionMs=5933 volume=96
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.318Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.319Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.320Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PAUSED positionMs=11888 volume=96
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.321Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" state=STATUS_PAUSED positionMs=11888 volume=96
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.321Z level=INFO msg="emitting player state changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" state=STATUS_PAUSED positionMs=11888 volume=96
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.322Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.323Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.323Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%03,10.110.1.112:52211 @ 0x238bda0" id= title="Nocturne in a Minor"
May 27 18:05:08 rivoplus volumio5-onboarding[3718]: time=2026-05-27T22:05:08.324Z level=INFO msg="emitting player metadata changed event" component=server peer="10.110.1.112:52211 @ 0x23820f0" id= title="Nocturne in a Minor"
May 27 18:05:08 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:05:08 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:05:08 rivoplus volumio[3183]: info: Updating RAAT Signal Path
May 27 18:05:08 rivoplus volumio[3183]: info: MCU Signalled Playback Inactive
May 27 18:05:20 rivoplus sudo[5247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 27 18:05:20 rivoplus sudo[5247]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:05:20 rivoplus sudo[5247]: pam_unix(sudo:session): session closed for user root
May 27 18:05:20 rivoplus sudo[5250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 27 18:05:20 rivoplus sudo[5250]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 27 18:05:20 rivoplus sudo[5250]: pam_unix(sudo:session): session closed for user root
May 27 18:05:20 rivoplus volumio[3183]: verbose: New Socket.io Connection to 10.110.1.31 from 10.110.1.112 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 10
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetVisibleSources
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 27 18:05:20 rivoplus volumio[3183]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
May 27 18:05:20 rivoplus volumio[3183]: info: Received Get System Info
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 18:05:20 rivoplus volumio[3183]: info: Discovery: Getting this device information
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:20 rivoplus volumio[3183]: info: Listing playlists
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin
May 27 18:05:20 rivoplus volumio[3183]: info: FusionDsp - Choose a preset
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs
May 27 18:05:20 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection
May 27 18:05:20 rivoplus volumio[3183]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json
May 27 18:05:21 rivoplus volumio[3183]: info: Received Get System Version
May 27 18:05:21 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 27 18:05:22 rivoplus volumio[3183]: info: Received Get System Info
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 18:05:22 rivoplus volumio[3183]: info: Discovery: Getting this device information
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 27 18:05:22 rivoplus volumio[3183]: info: Received Get System Info
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 18:05:22 rivoplus volumio[3183]: info: Discovery: Getting this device information
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:22 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 18:05:30 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
May 27 18:05:35 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:36 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 27 18:05:36 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
May 27 18:05:36 rivoplus volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin
May 27 18:05:36 rivoplus volumio[3183]: info: FusionDsp - Choose a preset
May 27 18:05:36 rivoplus volumio[3183]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json
May 27 18:05:37 rivoplus volumio[3183]: info: Executing endpoint metavolumio
May 27 18:05:37 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
May 27 18:05:37 rivoplus volumio[3183]: info: Executing endpoint metavolumio
May 27 18:05:37 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
May 27 18:05:37 rivoplus volumio[3183]: info: Executing endpoint metavolumio
May 27 18:05:37 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 27 18:05:38 rivoplus volumio[3183]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
May 27 18:05:38 rivoplus volumio[3183]: info: Received Get System Version
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 18:05:38 rivoplus volumio[3183]: info: Received Get System Info
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 18:05:38 rivoplus volumio[3183]: info: Discovery: Getting this device information
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::volumioGetState
May 27 18:05:38 rivoplus volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 18:05:44 rivoplus volumio[3183]: info: Starting Uninstall of plugin audio_interface - fusiondsp
May 27 18:05:44 rivoplus volumio[3183]: info: Uninstalling plugin fusiondsp
May 27 18:05:44 rivoplus volumio[3183]: info: FusionDsp - Stopping FusionDsp service
May 27 18:05:44 rivoplus volumio[3183]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 18:05:44 rivoplus volumio[3183]: TypeError: Cannot read property 'stop' of null
May 27 18:05:44 rivoplus volumio[3183]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:109:23)
May 27 18:05:44 rivoplus volumio[3183]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30)
May 27 18:05:44 rivoplus volumio[3183]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10)
May 27 18:05:44 rivoplus volumio[3183]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22)
May 27 18:05:44 rivoplus volumio[3183]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1271:45)
May 27 18:05:44 rivoplus volumio[3183]: at Socket.emit (events.js:400:28)
May 27 18:05:44 rivoplus volumio[3183]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
May 27 18:05:44 rivoplus volumio[3183]: at processTicksAndRejections (internal/process/task_queues.js:77:11)
May 27 18:05:44 rivoplus volumio[3183]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 18:05:45 rivoplus sudo[5360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-27 18:04
May 27 18:05:45 rivoplus sudo[5360]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="rivoplus"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:19:27 AM CET"
VOLUMIO_VERSION="3.912"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Rivo Plus"
VOLUMIO_HASH="a7285124ffc88c43265bb2db03526f6a"