-- Logs begin at Mon 2025-12-22 10:54:18 CET, end at Mon 2025-12-22 11:58:53 CET. -- Dec 22 11:57:04 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:57:04 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:57:04 rivoplus qobuz-connect[10503]: 20251222 11:57:04.994 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:57:04 rivoplus qobuz-connect[10503]: 20251222 11:57:04.994 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:57:04 rivoplus qobuz-connect[10503]: 20251222 11:57:04.994 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:57:04 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:04 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:57:04 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:57:04 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:57:04 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:57:05 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:05 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:57:05 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:57:05 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:05 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:05 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:57:14 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:57:14 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:57:14 rivoplus qobuz-connect[10503]: 20251222 11:57:14.995 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:57:14 rivoplus qobuz-connect[10503]: 20251222 11:57:14.995 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:57:14 rivoplus qobuz-connect[10503]: 20251222 11:57:14.995 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:57:14 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:14 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:57:14 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:57:14 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:57:14 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:57:15 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:15 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:57:15 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:57:15 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:15 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:15 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:57:24 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:57:24 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:57:24 rivoplus qobuz-connect[10503]: 20251222 11:57:24.996 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:57:24 rivoplus qobuz-connect[10503]: 20251222 11:57:24.996 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:57:24 rivoplus qobuz-connect[10503]: 20251222 11:57:24.996 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:57:24 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:24 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:57:24 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:57:24 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:57:24 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:57:25 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:25 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:57:25 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:57:25 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:25 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:25 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:57:34 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:57:34 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:57:34 rivoplus qobuz-connect[10503]: 20251222 11:57:34.996 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:57:34 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:34 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:57:34 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:57:34 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:57:34 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:57:35 rivoplus qobuz-connect[10503]: 20251222 11:57:35.000 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:57:35 rivoplus qobuz-connect[10503]: 20251222 11:57:35.000 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:57:35 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:35 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:57:35 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:57:35 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:35 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:35 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:57:44 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:57:44 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:57:44 rivoplus qobuz-connect[10503]: 20251222 11:57:44.997 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:57:44 rivoplus qobuz-connect[10503]: 20251222 11:57:44.997 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:57:45 rivoplus qobuz-connect[10503]: 20251222 11:57:44.997 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:57:45 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:45 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:57:45 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:57:45 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:57:45 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:57:45 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:45 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:57:45 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:57:45 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:45 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:45 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:57:54 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:57:54 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:57:55 rivoplus qobuz-connect[10503]: 20251222 11:57:55.008 [10503.10503] WARNING SampleApp: Unable to get buffered frame count from ALSA audio sink, trying to recover Dec 22 11:57:55 rivoplus qobuz-connect[10503]: 20251222 11:57:55.009 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:57:55 rivoplus qobuz-connect[10503]: 20251222 11:57:55.009 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:57:55 rivoplus qobuz-connect[10503]: 20251222 11:57:55.009 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:57:55 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:55 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:57:55 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:57:55 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:57:55 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:57:55 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:57:55 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:57:55 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:57:55 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:55 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:57:55 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:00 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:02 rivoplus volumio[3180]: info: Executing endpoint metavolumio Dec 22 11:58:02 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 11:58:02 rivoplus volumio[3180]: info: Executing endpoint metavolumio Dec 22 11:58:02 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 11:58:02 rivoplus volumio[3180]: info: Executing endpoint metavolumio Dec 22 11:58:02 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 11:58:04 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:58:04 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:58:05 rivoplus qobuz-connect[10503]: 20251222 11:58:05.018 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:58:05 rivoplus qobuz-connect[10503]: 20251222 11:58:05.018 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:58:05 rivoplus qobuz-connect[10503]: 20251222 11:58:05.018 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:05 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:05 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:05 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:05 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:05 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:05 rivoplus volumio[3180]: info: Executing endpoint metavolumio Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 11:58:05 rivoplus volumio[3180]: info: Executing endpoint metavolumio Dec 22 11:58:05 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 11:58:09 rivoplus volumio[3180]: error: Failed request for metavolumio API Dec 22 11:58:09 rivoplus volumio[3180]: error: Failed request for metavolumio API Dec 22 11:58:09 rivoplus volumio[3180]: error: Failed request for metavolumio API Dec 22 11:58:10 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 22 11:58:10 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:12 rivoplus volumio[3180]: error: Failed request for metavolumio API Dec 22 11:58:12 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 22 11:58:12 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:14 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:58:14 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:58:14 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 22 11:58:14 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:15 rivoplus qobuz-connect[10503]: 20251222 11:58:15.018 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:58:15 rivoplus qobuz-connect[10503]: 20251222 11:58:15.018 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:58:15 rivoplus qobuz-connect[10503]: 20251222 11:58:15.018 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:58:15 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:15 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:15 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:15 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:15 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:15 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:15 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:15 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:15 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:15 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:17 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 22 11:58:17 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:19 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 22 11:58:20 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:20.943+01:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 22 11:58:21 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:21.180+01:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 22 11:58:23 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:24 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:58:24 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:58:25 rivoplus qobuz-connect[10503]: 20251222 11:58:25.019 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:58:25 rivoplus qobuz-connect[10503]: 20251222 11:58:25.019 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:58:25 rivoplus qobuz-connect[10503]: 20251222 11:58:25.019 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:58:25 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:25 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:25 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:25 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:25 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:25 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:25 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:25 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:25 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:25 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:34 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:58:34 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:58:35 rivoplus qobuz-connect[10503]: 20251222 11:58:35.030 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:58:35 rivoplus qobuz-connect[10503]: 20251222 11:58:35.030 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:58:35 rivoplus qobuz-connect[10503]: 20251222 11:58:35.030 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:58:35 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:35 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:35 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:35 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:35 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:35 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:35 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:35 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:35 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:35 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:36 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 22 11:58:36 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@e8a0e541a2e95e1dee96 Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@db6bf987a95fb46b9b7c Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@f82f50ce957ea0ee61b6 Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@caee95392f58d55bcdd2 Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@a2ea0bb4991f28499b90 Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@a3710bd827e444accc50 Dec 22 11:58:36 rivoplus volumio[3180]: info: Preloading song: upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@1854e15049a6cb808560 Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@e8a0e541a2e95e1dee96 in service upnp_browser Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@db6bf987a95fb46b9b7c in service upnp_browser Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@f82f50ce957ea0ee61b6 in service upnp_browser Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@caee95392f58d55bcdd2 in service upnp_browser Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@a2ea0bb4991f28499b90 in service upnp_browser Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@a3710bd827e444accc50 in service upnp_browser Dec 22 11:58:36 rivoplus volumio[3180]: info: Exploding uri upnp/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@1854e15049a6cb808560 in service upnp_browser Dec 22 11:58:39 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::ClearQueue Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::stop Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::serviceStop Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::serviceStop Dec 22 11:58:39 rivoplus volumio[3180]: info: QobuzConnect: Received stop Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.497 [10503.10503] INFO MediaEngine: [0xabc93398]: Stopping playback, keeping tracks Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.497 [10503.10503] INFO AudioRenderer: [0xabc935b8]: Stopping audio renderer Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.498 [10503.10503] INFO SampleApp: Stopping playback Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::clearPlayQueue Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::saveQueue Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushQueue Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::addQueueItems Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::addQueueItems Dec 22 11:58:39 rivoplus volumio[3180]: info: Preload queue cleared Dec 22 11:58:39 rivoplus volumio[3180]: info: Adding Item to queue: upnp/folder/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@08cb03e15c399eaee54f Dec 22 11:58:39 rivoplus volumio[3180]: info: Exploding uri upnp/folder/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@08cb03e15c399eaee54f in service upnp_browser Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.512 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Clearing all streams Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.512 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 8]: Disposing of audio stream Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.512 [10503.10503] INFO ContentFetcher: [0xabdbd988]: Canceling download Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.521 [10503.10503] INFO AudioStreamManager: [0xabc93480]: New stream: 10 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.521 [10503.10503] INFO HttpDownloader: [0xabe1fa58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=6ae98b9d836833cd5b34f8c3d2b0e400&request_ts=1766401119&track_id=66483289 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.521 [10503.10503] INFO HttpDownloader: [0xac061860]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=66483289 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.521 [10503.10503] INFO HttpDownloader: [0xac0228f0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=8ef3662d6bd68a9327e99e37beeae815&request_ts=1766401119&track_id=66483289 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.521 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 10]: Running audio stream Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.522 [10503.10503] INFO AudioStreamManager: [0xabc93480]: New stream: 11 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.522 [10503.10503] INFO HttpDownloader: [0xabf77680]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=45f3c8ddcb9f6a4b24bf09dd6476036b&request_ts=1766401119&track_id=66483290 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.522 [10503.10503] INFO HttpDownloader: [0xabcd2420]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=66483290 Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.522 [10503.10503] INFO HttpDownloader: [0xac0485a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=42b656a37fa7885116fcbf4707e611a3&request_ts=1766401119&track_id=66483290 Dec 22 11:58:39 rivoplus volumio[3180]: info: QobuzConnect: playback_stop received, deferred solved Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO SampleApp: Playback state changed: Stopped Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO StreamingEventReporter: [0xabc93ef0]: Reporting streaming ended event Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO HttpDownloader: [0xabc93f48]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO ProtocolHandler: [0xabc93ad8]: Need to send state update Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO QConnectMessageSender: [0xabcc6e28]: Sending StateUpdated message Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO SampleApp: [Stream 8]: Audio stream has been disposed of Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.557 [10503.10503] INFO QwspMessageSender: [0xabcc6e18]: Sending Payload message Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushQueue Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::saveQueue Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::updateTrackBlock Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrackBlock Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPlay Dec 22 11:58:39 rivoplus volumio[3180]: verbose: UNSET VOLATILE: Service: qobuzconnect Dec 22 11:58:39 rivoplus volumio[3180]: info: QobuzConnect: onUnsetVolatile() called, relinquishing Volumio State to another service Dec 22 11:58:39 rivoplus volumio[3180]: info: QobuzConnect: Received stop Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:39 rivoplus qobuz-connect[10503]: 20251222 11:58:39.636 [10503.10503] INFO MediaEngine: [0xabc93398]: Stopping playback, keeping tracks Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::play index 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::stop Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::stPlaybackTimer Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::updateTrackBlock Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrackBlock Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:39 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::serviceStop Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::serviceStop Dec 22 11:58:39 rivoplus volumio[3180]: info: [1766401119657] ControllerUPNPBrowser::stop Dec 22 11:58:39 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand stop Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:39 rivoplus volumio[3180]: info: sendMpdCommand stop took 45 milliseconds Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::play index undefined Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::startPlaybackTimer Dec 22 11:58:39 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:39 rivoplus volumio[3180]: info: [1766401119708] ControllerUPNPBrowser::clearAddPlayTrack Dec 22 11:58:39 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand stop Dec 22 11:58:39 rivoplus volumio[3180]: info: sendMpdCommand stop took 3 milliseconds Dec 22 11:58:39 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand clear Dec 22 11:58:39 rivoplus volumio[3180]: info: Dec 22 11:58:39 rivoplus volumio[3180]: ---------------------------- MPD announces system playlist update Dec 22 11:58:39 rivoplus volumio[3180]: info: Ignoring MPD Status Update Dec 22 11:58:39 rivoplus volumio[3180]: info: sendMpdCommand clear took 7 milliseconds Dec 22 11:58:39 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4" Dec 22 11:58:39 rivoplus volumio[3180]: error: updateQueue error: null Dec 22 11:58:39 rivoplus volumio[3180]: info: ------------------------------ 39ms Dec 22 11:58:39 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4" Dec 22 11:58:39 rivoplus volumio[3180]: info: Dec 22 11:58:39 rivoplus volumio[3180]: ---------------------------- MPD announces system playlist update Dec 22 11:58:39 rivoplus volumio[3180]: info: Ignoring MPD Status Update Dec 22 11:58:39 rivoplus volumio[3180]: info: sendMpdCommand add "http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4" took 3 milliseconds Dec 22 11:58:39 rivoplus volumio[3180]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 22 11:58:39 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand play Dec 22 11:58:39 rivoplus volumio[3180]: info: ------------------------------ 8ms Dec 22 11:58:39 rivoplus volumio[3180]: info: sendMpdCommand play took 5 milliseconds Dec 22 11:58:39 rivoplus volumio[3180]: info: MCU Signalled Playback Inactive Dec 22 11:58:40 rivoplus volumio[3180]: info: Dec 22 11:58:40 rivoplus volumio[3180]: ---------------------------- MPD announces state update: player Dec 22 11:58:40 rivoplus volumio[3180]: info: ControllerMpd::getState Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Dec 22 11:58:40 rivoplus volumio[3180]: info: Dec 22 11:58:40 rivoplus volumio[3180]: ---------------------------- MPD announces state update: player Dec 22 11:58:40 rivoplus volumio[3180]: info: sendMpdCommand status took 55 milliseconds Dec 22 11:58:40 rivoplus volumio[3180]: info: ControllerMpd::getState Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::parseState Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 22 11:58:40 rivoplus volumio[3180]: info: sendMpdCommand status took 20 milliseconds Dec 22 11:58:40 rivoplus volumio[3180]: info: sendMpdCommand playlistinfo took 18 milliseconds Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::parseState Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::parseTrackInfo Dec 22 11:58:40 rivoplus volumio[3180]: info: ControllerMpd::pushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:40 rivoplus volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":375,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"265 Kbps","isStreaming":false,"title":"file.mp4","artist":null,"album":null,"uri":"http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4","trackType":"mp4"} Dec 22 11:58:40 rivoplus volumio[3180]: verbose: CURRENT POSITION 0 Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreStateMachine::syncState stateService play Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreStateMachine::syncState currentStatus stop Dec 22 11:58:40 rivoplus volumio[3180]: info: ------------------------------ 105ms Dec 22 11:58:40 rivoplus volumio[3180]: info: sendMpdCommand playlistinfo took 23 milliseconds Dec 22 11:58:40 rivoplus volumio[3180]: verbose: ControllerMpd::parseTrackInfo Dec 22 11:58:40 rivoplus volumio[3180]: info: ControllerMpd::pushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:40 rivoplus volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1234,"duration":375,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"265 Kbps","isStreaming":false,"title":"file.mp4","artist":null,"album":null,"uri":"http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4","trackType":"mp4"} Dec 22 11:58:40 rivoplus volumio[3180]: verbose: CURRENT POSITION 0 Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreStateMachine::syncState stateService play Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreStateMachine::syncState currentStatus play Dec 22 11:58:40 rivoplus volumio[3180]: info: Received an update from plugin. extracting info from payload Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:40 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:40 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:40 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:40.300+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.51.167:58145 Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:40 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:40 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:40 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:40 rivoplus volumio[3180]: info: ------------------------------ 124ms Dec 22 11:58:40 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:40 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:40 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:40 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:40 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:40 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:40 rivoplus volumio[3180]: info: MCU Signalled Playback Active Dec 22 11:58:40 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:40.861+01:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 22 11:58:41 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:41.281+01:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 22 11:58:42 rivoplus volumio[3180]: info: Executing endpoint metavolumio Dec 22 11:58:42 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 11:58:43 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:43.354+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.51.167:58169 Dec 22 11:58:44 rivoplus volumio[3180]: info: Discovery: Remote connection error: 192.168.51.124 Dec 22 11:58:44 rivoplus volumio[3180]: info: Discovery: Remote connection timeout: 192.168.51.124 Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.588 [10503.10503] ERROR HttpClient: [0xabfea5d8]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.588 [10503.10503] INFO HttpClient: [0xabfea5d8]: Retrying connection (1 out of 1) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] ERROR HttpClient: [0xabfea208]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] INFO HttpClient: [0xabfea208]: Retrying connection (1 out of 1) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] ERROR HttpClient: [0xac171948]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] INFO HttpClient: [0xac171948]: Retrying connection (1 out of 1) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] ERROR HttpClient: [0xabf729c0]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] INFO HttpClient: [0xabf729c0]: Retrying connection (1 out of 1) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] ERROR HttpClient: [0xabdbda10]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] INFO HttpClient: [0xabdbda10]: Retrying connection (1 out of 1) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] ERROR HttpClient: [0xabe46f48]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] INFO HttpClient: [0xabe46f48]: Retrying connection (1 out of 1) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] ERROR HttpClient: [0xabfbf0b8]: Client finished: Timeout was reached (28) Dec 22 11:58:44 rivoplus qobuz-connect[10503]: 20251222 11:58:44.612 [10503.10503] INFO HttpClient: [0xabfbf0b8]: Retrying connection (1 out of 1) Dec 22 11:58:45 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:45.172+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.51.167:58174 Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.199 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 10]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=242551&eid=66483289&fmt=6&profile=raw&app_id=174516466&cid=2169684&etsp=1766404725&hmac=gtR2cPWz2p9mrh7ImwaTSm2mKJQ Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.258 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 10]: Metadata became available: Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.258 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Title: Thinking You Over Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.258 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Artist: Melissa Forbes Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.259 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Album: No More Mondays Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.259 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Album art URL: https://static.qobuz.com/images/covers/xc/3s/gbmu9w1ga3sxc_600.jpg Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.278 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 11]: stream information have been fetched Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.282 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 11]: Metadata became available: Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.282 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Title: The Weekday Sun Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.282 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Artist: Melissa Forbes Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.282 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Album: No More Mondays Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.282 [10503.10503] INFO AudioStreamManager: [0xabc93480]: Album art URL: https://static.qobuz.com/images/covers/xc/3s/gbmu9w1ga3sxc_600.jpg Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.290 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 11]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=242551&eid=66483290&fmt=6&profile=raw&app_id=174516466&cid=2169684&etsp=1766404725&hmac=BJ_-igOjbbbw95gD3tEBRFhcyaU Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.294 [10503.10503] INFO AudioStreamManager: [0xabc93480]: [Stream 10]: stream information have been fetched Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.294 [10503.10503] INFO UrlAudioSource: [0xac1b9b18]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=242551&eid=66483289&fmt=6&profile=raw&app_id=174516466&cid=2169684&etsp=1766404725&hmac=gtR2cPWz2p9mrh7ImwaTSm2mKJQ Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.294 [10503.10503] INFO ContentFetcher: [0xac113168]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=242551&eid=66483289&fmt=6&profile=raw&app_id=174516466&cid=2169684&etsp=1766404725&hmac=gtR2cPWz2p9mrh7ImwaTSm2mKJQ, offset: 0 Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.295 [10503.10503] INFO SampleApp: [Stream 10]: New audio stream (starting from 0ms) Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.295 [10503.10503] INFO SampleApp: [Stream 10]: Stream metadata became available: Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.295 [10503.10503] INFO SampleApp: Title: Thinking You Over Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.295 [10503.10503] INFO SampleApp: Artist: Melissa Forbes Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.295 [10503.10503] INFO SampleApp: Album: No More Mondays Dec 22 11:58:45 rivoplus qobuz-connect[10503]: 20251222 11:58:45.295 [10503.10503] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/xc/3s/gbmu9w1ga3sxc_600.jpg Dec 22 11:58:45 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:46 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:48 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 22 11:58:48 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 22 11:58:48 rivoplus volumio[3180]: info: Discovery: Getting this device information Dec 22 11:58:48 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:48 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 22 11:58:48 rivoplus volumio[3180]: verbose: New Socket.io Connection to 192.168.51.55:3000 from 192.168.51.188 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Dec 22 11:58:48 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 22 11:58:48 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 22 11:58:49 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:49.102+01:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.51.188:59383 error="read tcp 192.168.51.55:7331->192.168.51.188:59383: read: connection reset by peer" Dec 22 11:58:49 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:49.103+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.51.188:59383 Dec 22 11:58:49 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:49.103+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.51.188:59383 Dec 22 11:58:49 rivoplus volumio[3180]: error: Failed request for metavolumio API Dec 22 11:58:50 rivoplus qobuz-connect[10503]: 20251222 11:58:50.383 [10503.10503] ERROR HttpClient: [0xabdbda10]: Client finished: Timeout was reached (28) Dec 22 11:58:50 rivoplus qobuz-connect[10503]: 20251222 11:58:50.383 [10503.10503] INFO HttpClient: [0xabdbda10]: Retrying connection (1 out of 1) Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreCommandRouter::volumioSeek Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreStateMachine::seek Dec 22 11:58:50 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:50 rivoplus volumio[3180]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4","realUri":"upnp/folder/http://192.168.51.167:32469/ContentDirectory/28f07696-d61c-e642-65ed-dfdcd708ec23/control.xml@08cb03e15c399eaee54f","type":"song","albumart":"http://192.168.51.167:32469/proxy/4da76ed94b32d33ed3bc/albumart.jpg","artist":"Jafia Namuel","album":"One Love Train (USA Edition)","name":"Fire","title":"Fire","duration":374} Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreStateMachine::startPlaybackTimer Dec 22 11:58:50 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:50 rivoplus volumio[3180]: info: [1766401130983] ControllerUPNPBrowser::seek Dec 22 11:58:50 rivoplus volumio[3180]: info: ControllerMpd::seek Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:50 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:50 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:50 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:51 rivoplus volumio[3180]: error: null Dec 22 11:58:51 rivoplus volumio[3180]: info: Dec 22 11:58:51 rivoplus volumio[3180]: ---------------------------- MPD announces state update: player Dec 22 11:58:51 rivoplus volumio[3180]: info: ControllerMpd::getState Dec 22 11:58:51 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Dec 22 11:58:51 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:51 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:51 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:51 rivoplus volumio[3180]: info: sendMpdCommand status took 26 milliseconds Dec 22 11:58:51 rivoplus volumio[3180]: verbose: ControllerMpd::parseState Dec 22 11:58:51 rivoplus volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 22 11:58:51 rivoplus volumio[3180]: info: sendMpdCommand playlistinfo took 7 milliseconds Dec 22 11:58:51 rivoplus volumio[3180]: verbose: ControllerMpd::parseTrackInfo Dec 22 11:58:51 rivoplus volumio[3180]: info: ControllerMpd::pushState Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreCommandRouter::servicePushState Dec 22 11:58:51 rivoplus volumio[3180]: info: CorePlayQueue::getTrack 0 Dec 22 11:58:51 rivoplus volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":79233,"duration":375,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"265 Kbps","isStreaming":false,"title":"file.mp4","artist":null,"album":null,"uri":"http://192.168.51.167:32469/object/e8a0e541a2e95e1dee96/file.mp4","trackType":"mp4"} Dec 22 11:58:51 rivoplus volumio[3180]: verbose: CURRENT POSITION 0 Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreStateMachine::syncState stateService play Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreStateMachine::syncState currentStatus play Dec 22 11:58:51 rivoplus volumio[3180]: info: Received an update from plugin. extracting info from payload Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:51 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:51 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreStateMachine::pushState Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreCommandRouter::volumioPushState Dec 22 11:58:51 rivoplus volumio[3180]: info: CoreCommandRouter::volumioGetState Dec 22 11:58:51 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output update for this device Dec 22 11:58:51 rivoplus volumio[3180]: info: MRS: Pushing multiroomSync output Dec 22 11:58:51 rivoplus volumio[3180]: info: ------------------------------ 95ms Dec 22 11:58:51 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:51 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:51 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:51 rivoplus volumio[3180]: info: Signalling Playback active due to playback status change Dec 22 11:58:51 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:51 rivoplus volumio[3180]: info: Updating RAAT Signal Path Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.220 [10503.10503] INFO UrlAudioSource: [0xac1b9b18]: Content info extracted Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.221 [10503.10503] INFO UrlAudioSource: [0xac1b9b18]: Size: 22876483 Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.223 [10503.16312] INFO AudioDecoder: [0xac38a6c8]: Stream info: Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.224 [10503.16312] INFO AudioDecoder: [0xac38a6c8]: Total samples: 10151232 Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.224 [10503.16312] INFO AudioDecoder: [0xac38a6c8]: Sample rate: 44100 Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.224 [10503.16312] INFO AudioDecoder: [0xac38a6c8]: Channel count: 2 Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.224 [10503.16312] INFO AudioDecoder: [0xac38a6c8]: Bits per sample: 16 Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.224 [10503.16312] INFO AudioDecoder: [0xac38a6c8]: Duration: 230186 Dec 22 11:58:51 rivoplus qobuz-connect[10503]: 20251222 11:58:51.224 [10503.10503] INFO UrlAudioSource: [0xac1b9b18]: Audio properties have changed Dec 22 11:58:51 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:51.721+01:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 22 11:58:52 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:52.383+01:00 level=WARN msg="pending write acknowledgment timed out, retrying" component=conn/ble addr=3 Dec 22 11:58:52 rivoplus volumio[3180]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 11:58:52 rivoplus volumio[3180]: Error: connect ECONNREFUSED 0.0.0.0:443 Dec 22 11:58:52 rivoplus volumio[3180]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Dec 22 11:58:52 rivoplus volumio[3180]: errno: -111, Dec 22 11:58:52 rivoplus volumio[3180]: code: 'ECONNREFUSED', Dec 22 11:58:52 rivoplus volumio[3180]: syscall: 'connect', Dec 22 11:58:52 rivoplus volumio[3180]: address: '0.0.0.0', Dec 22 11:58:52 rivoplus volumio[3180]: port: 443 Dec 22 11:58:52 rivoplus volumio[3180]: } Dec 22 11:58:52 rivoplus volumio[3180]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 11:58:52 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:52.860+01:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 22 11:58:53 rivoplus volumio5-onboarding[3908]: time=2025-12-22T11:58:53.100+01:00 level=WARN msg="received acknowledgment for source with no pending writes" component=conn/ble data=0300 addr=3 Dec 22 11:58:53 rivoplus sudo[16322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-22 11:57 Dec 22 11:58:53 rivoplus sudo[16322]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:47:33 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="9e8aa5d6afb5e5d87a87bafae7aa5647"