-- Logs begin at Sat 2025-12-20 06:28:41 JST, end at Sat 2025-12-20 10:00:00 JST. -- Dec 20 09:58:04 rivo qobuz-connect[5151]: 20251220 09:58:04.307 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:58:04 rivo qobuz-connect[5151]: 20251220 09:58:04.307 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:58:04 rivo qobuz-connect[5151]: 20251220 09:58:04.307 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:58:04 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:04 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:58:04 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:58:04 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:58:04 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:58:04 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:04 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:58:04 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:04 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:05 rivo go-librespot[3545]: time="2025-12-20T09:58:05+09:00" level=trace msg="sent dealer ping" Dec 20 09:58:06 rivo go-librespot[3545]: time="2025-12-20T09:58:06+09:00" level=trace msg="received dealer pong" Dec 20 09:58:14 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:14 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:58:14 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:58:14 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:58:14 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:58:14 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:14 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:58:14 rivo qobuz-connect[5151]: 20251220 09:58:14.317 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:58:14 rivo qobuz-connect[5151]: 20251220 09:58:14.317 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:58:14 rivo qobuz-connect[5151]: 20251220 09:58:14.318 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:58:14 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:14 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:24 rivo qobuz-connect[5151]: 20251220 09:58:24.308 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:58:24 rivo qobuz-connect[5151]: 20251220 09:58:24.308 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:58:24 rivo qobuz-connect[5151]: 20251220 09:58:24.309 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:58:24 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:24 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:58:24 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:58:24 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:58:24 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:58:24 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:24 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:58:24 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:24 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:34 rivo qobuz-connect[5151]: 20251220 09:58:34.310 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:58:34 rivo qobuz-connect[5151]: 20251220 09:58:34.310 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:58:34 rivo qobuz-connect[5151]: 20251220 09:58:34.310 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:58:34 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:34 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:58:34 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:58:34 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:58:34 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:58:34 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:34 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:58:34 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:34 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:35 rivo go-librespot[3545]: time="2025-12-20T09:58:35+09:00" level=trace msg="sent dealer ping" Dec 20 09:58:36 rivo go-librespot[3545]: time="2025-12-20T09:58:36+09:00" level=trace msg="received dealer pong" Dec 20 09:58:36 rivo go-librespot[3545]: time="2025-12-20T09:58:36+09:00" level=trace msg="received accesspoint ping" Dec 20 09:58:36 rivo go-librespot[3545]: time="2025-12-20T09:58:36+09:00" level=trace msg="received accesspoint pong ack" Dec 20 09:58:44 rivo qobuz-connect[5151]: 20251220 09:58:44.311 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:58:44 rivo qobuz-connect[5151]: 20251220 09:58:44.311 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:58:44 rivo qobuz-connect[5151]: 20251220 09:58:44.311 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:58:44 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:44 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:58:44 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:58:44 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:58:44 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:58:44 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:44 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:58:44 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:44 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:54 rivo qobuz-connect[5151]: 20251220 09:58:54.312 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:58:54 rivo qobuz-connect[5151]: 20251220 09:58:54.312 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:58:54 rivo qobuz-connect[5151]: 20251220 09:58:54.312 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:58:54 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:54 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:58:54 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:58:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:58:54 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:58:54 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:58:54 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:58:54 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:58:54 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:04 rivo qobuz-connect[5151]: 20251220 09:59:04.312 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:04 rivo qobuz-connect[5151]: 20251220 09:59:04.312 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:04 rivo qobuz-connect[5151]: 20251220 09:59:04.313 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:04 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:04 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:04 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:04 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:04 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:04 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:04 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:04 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:04 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:05 rivo go-librespot[3545]: time="2025-12-20T09:59:05+09:00" level=trace msg="sent dealer ping" Dec 20 09:59:06 rivo go-librespot[3545]: time="2025-12-20T09:59:06+09:00" level=trace msg="received dealer pong" Dec 20 09:59:14 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:14 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:14 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:14 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:14 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:14 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:14 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:14 rivo qobuz-connect[5151]: 20251220 09:59:14.317 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:14 rivo qobuz-connect[5151]: 20251220 09:59:14.317 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:14 rivo qobuz-connect[5151]: 20251220 09:59:14.318 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:14 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:14 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.942 [5151.5151] INFO AudioStreamManager: [0xabec3ec0]: [Stream 30]: Running audio stream Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.942 [5151.5151] INFO UrlAudioSource: [0xac32f038]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=3487157&eid=56039514&fmt=7&profile=raw&app_id=174516466&cid=3384193&etsp=1766195744&hmac=vKVLVhIjwYn6NxpXAQs1yvlvY-o Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.942 [5151.5151] INFO ContentFetcher: [0xac5e60e0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=3487157&eid=56039514&fmt=7&profile=raw&app_id=174516466&cid=3384193&etsp=1766195744&hmac=vKVLVhIjwYn6NxpXAQs1yvlvY-o, offset: 0 Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.975 [5151.5151] INFO SampleApp: [Stream 30]: New audio stream (starting from 0ms) Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.976 [5151.5151] INFO SampleApp: [Stream 30]: Stream metadata became available: Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.976 [5151.5151] INFO SampleApp: Title: 漂白 Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.976 [5151.5151] INFO SampleApp: Artist: あいみょん Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.976 [5151.5151] INFO SampleApp: Album: 青春のエキサイトメント Dec 20 09:59:17 rivo qobuz-connect[5151]: 20251220 09:59:17.976 [5151.5151] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/ta/52/s1sayfhsf52ta_600.jpg Dec 20 09:59:17 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.598 [5151.5151] INFO UrlAudioSource: [0xac32f038]: Content info extracted Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.598 [5151.5151] INFO UrlAudioSource: [0xac32f038]: Size: 67076280 Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.601 [5151.19410] INFO AudioDecoder: [0xabffa9e8]: Stream info: Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.601 [5151.19410] INFO AudioDecoder: [0xabffa9e8]: Total samples: 13979520 Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.602 [5151.19410] INFO AudioDecoder: [0xabffa9e8]: Sample rate: 48000 Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.602 [5151.19410] INFO AudioDecoder: [0xabffa9e8]: Channel count: 2 Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.603 [5151.19410] INFO AudioDecoder: [0xabffa9e8]: Bits per sample: 24 Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.603 [5151.19410] INFO AudioDecoder: [0xabffa9e8]: Duration: 291240 Dec 20 09:59:20 rivo qobuz-connect[5151]: 20251220 09:59:20.603 [5151.5151] INFO UrlAudioSource: [0xac32f038]: Audio properties have changed Dec 20 09:59:24 rivo qobuz-connect[5151]: 20251220 09:59:24.313 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:24 rivo qobuz-connect[5151]: 20251220 09:59:24.313 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:24 rivo qobuz-connect[5151]: 20251220 09:59:24.313 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:24 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:24 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:24 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:24 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:24 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:24 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:24 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:24 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:24 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:25 rivo qobuz-connect[5151]: 20251220 09:59:25.535 [5151.5151] INFO AudioStreamManager: [0xabec3ec0]: [Stream 29]: Audio stream has finished Dec 20 09:59:25 rivo qobuz-connect[5151]: 20251220 09:59:25.535 [5151.5151] INFO SampleApp: [Stream 29]: Audio stream finished Dec 20 09:59:25 rivo qobuz-connect[5151]: 20251220 09:59:25.536 [5151.5151] INFO SampleApp: Playback is nearly finished Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.943 [5151.5151] INFO SampleApp: Playback has finished Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.943 [5151.5151] INFO AudioStreamManager: [0xabec3ec0]: [Stream 29]: Disposing of audio stream Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.943 [5151.5151] INFO ContentFetcher: [0xabfd1650]: Canceling download Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.946 [5151.5151] INFO SampleApp: [Stream 29]: Audio stream has been disposed of Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.946 [5151.5151] INFO StreamingEventReporter: [0xabec4930]: Reporting streaming ended event Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.946 [5151.5151] INFO HttpDownloader: [0xabec4988]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.946 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.946 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.947 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.948 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.948 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.948 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.948 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending FileAudioQualityChanged message Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.949 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.949 [5151.5151] INFO StreamingEventReporter: [0xabec4930]: Reporting streaming started event Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.949 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.949 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.950 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.965 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Received SetState message: Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.965 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Playing state: Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.965 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Playback position: Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.965 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Queue version: 11.2 Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.966 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Current track: Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.966 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Next track: TID: 4294967295, QID: -1, Context UUID: Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.966 [5151.5151] INFO MediaEngine: [0xabec3dd8]: Setting next track: NONE Dec 20 09:59:27 rivo qobuz-connect[5151]: 20251220 09:59:27.966 [5151.5151] INFO RendererActionAvailabilityManager: [0xabec4468]: Renderer action 'Next' is not available Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:27 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:27 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:27 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:27 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:27 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:27 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:27 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:27 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:27 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:27 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:27 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:27 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:28 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:28 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:28 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:28 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Received SetState message: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Playing state: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Playback position: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Queue version: 11.2 Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Current track: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Next track: TID: 4294967295, QID: -1, Context UUID: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.056 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Received SetState message: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.057 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Playing state: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.057 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Playback position: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.057 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Queue version: 11.2 Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.057 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Current track: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.057 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Next track: TID: 4294967295, QID: -1, Context UUID: Dec 20 09:59:28 rivo qobuz-connect[5151]: 20251220 09:59:28.457 [5151.5151] INFO HttpDownloader: [0xabec4988]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Dec 20 09:59:35 rivo go-librespot[3545]: time="2025-12-20T09:59:35+09:00" level=trace msg="sent dealer ping" Dec 20 09:59:36 rivo go-librespot[3545]: time="2025-12-20T09:59:36+09:00" level=trace msg="received dealer pong" Dec 20 09:59:37 rivo qobuz-connect[5151]: 20251220 09:59:37.949 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:37 rivo qobuz-connect[5151]: 20251220 09:59:37.949 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:37 rivo qobuz-connect[5151]: 20251220 09:59:37.950 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:37 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:37 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:37 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:37 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:37 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:37 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:37 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:37 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:47 rivo qobuz-connect[5151]: 20251220 09:59:47.949 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:47 rivo qobuz-connect[5151]: 20251220 09:59:47.949 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:47 rivo qobuz-connect[5151]: 20251220 09:59:47.949 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:47 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:47 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:47 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:47 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:47 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:47 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:47 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:47 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:54 rivo volumio5-onboarding[3786]: time=2025-12-20T09:59:54.120+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.11.4:55077 Dec 20 09:59:54 rivo volumio5-onboarding[3786]: time=2025-12-20T09:59:54.180+09:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.11.4:55077 @ 0x19aa720" latency=9.841023ms platform=PLATFORM_IOS version=4.251125.0 Dec 20 09:59:54 rivo volumio5-onboarding[3786]: time=2025-12-20T09:59:54.181+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.11.4:55077 @ 0x19aa720" latency=10.823646ms timeout=10s Dec 20 09:59:54 rivo volumio[3104]: info: Received Get System Info Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 20 09:59:54 rivo volumio[3104]: info: Discovery: Getting this device information Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 20 09:59:54 rivo volumio[3104]: xcb_connection_has_error() returned true Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 20 09:59:54 rivo kernel: aml_spdif_open Dec 20 09:59:54 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Dec 20 09:59:54 rivo kernel: spdif_a keep clk continuous Dec 20 09:59:54 rivo kernel: aml_spdif_close Dec 20 09:59:54 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Dec 20 09:59:54 rivo volumio[3104]: Invalid card number. Dec 20 09:59:54 rivo volumio[3104]: xcb_connection_has_error() returned true Dec 20 09:59:54 rivo volumio[3104]: amixer -c 5 info | grep "DCD-SX11" Dec 20 09:59:54 rivo volumio[3104]: xcb_connection_has_error() returned true Dec 20 09:59:54 rivo volumio[3104]: Card hw:5 'DCDSX11'/'D&M Holdings Inc. DCD-SX11 at usb-xhci-hcd.0.auto-1.4.2, high speed' Dec 20 09:59:54 rivo volumio[3104]: xcb_connection_has_error() returned true Dec 20 09:59:54 rivo volumio[3104]: amixer -c 5 info | grep "DCD-SX11" Dec 20 09:59:54 rivo volumio[3104]: xcb_connection_has_error() returned true Dec 20 09:59:54 rivo volumio[3104]: Card hw:5 'DCDSX11'/'D&M Holdings Inc. DCD-SX11 at usb-xhci-hcd.0.auto-1.4.2, high speed' Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 20 09:59:54 rivo volumio[3104]: info: Discovery: Getting this device information Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 20 09:59:54 rivo volumio[3104]: info: Received Get System Info Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 20 09:59:54 rivo volumio[3104]: info: Discovery: Getting this device information Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 20 09:59:54 rivo volumio[3104]: verbose: New Socket.io Connection to 192.168.11.6:3000 from 192.168.11.4 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 20 09:59:54 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 20 09:59:54 rivo volumio5-onboarding[3786]: time=2025-12-20T09:59:54.986+09:00 level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.11.4:55077 @ 0x19aa720" latency=11.431242ms timeout=10s from=APP_PAGE_ROOT Dec 20 09:59:55 rivo sudo[19514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 20 09:59:55 rivo sudo[19514]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 09:59:55 rivo sudo[19514]: pam_unix(sudo:session): session closed for user root Dec 20 09:59:55 rivo sudo[19518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 20 09:59:55 rivo sudo[19518]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 09:59:55 rivo sudo[19518]: pam_unix(sudo:session): session closed for user root Dec 20 09:59:55 rivo volumio[3104]: verbose: New Socket.io Connection to 192.168.11.6 from 192.168.11.4 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Dec 20 09:59:56 rivo sudo[19522]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 20 09:59:56 rivo sudo[19522]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 09:59:56 rivo sudo[19522]: pam_unix(sudo:session): session closed for user root Dec 20 09:59:56 rivo sudo[19526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 20 09:59:56 rivo sudo[19526]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 09:59:56 rivo sudo[19526]: pam_unix(sudo:session): session closed for user root Dec 20 09:59:56 rivo volumio[3104]: verbose: New Socket.io Connection to 192.168.11.6 from 192.168.11.4 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Dec 20 09:59:56 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:56 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 20 09:59:56 rivo volumio[3104]: info: Listing playlists Dec 20 09:59:56 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 20 09:59:56 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 20 09:59:56 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 20 09:59:56 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 20 09:59:57 rivo volumio[3104]: info: CoreCommandRouter::volumioGetQueue Dec 20 09:59:57 rivo volumio[3104]: info: CoreStateMachine::getQueue Dec 20 09:59:57 rivo volumio[3104]: info: CorePlayQueue::getQueue Dec 20 09:59:57 rivo qobuz-connect[5151]: 20251220 09:59:57.950 [5151.5151] INFO ProtocolHandler: [0xabec4518]: Need to send state update Dec 20 09:59:57 rivo qobuz-connect[5151]: 20251220 09:59:57.950 [5151.5151] INFO QConnectMessageSender: [0xabfa3680]: Sending StateUpdated message Dec 20 09:59:57 rivo qobuz-connect[5151]: 20251220 09:59:57.950 [5151.5151] INFO QwspMessageSender: [0xabfb8a00]: Sending Payload message Dec 20 09:59:57 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:57 rivo volumio[3104]: info: CoreCommandRouter::servicePushState Dec 20 09:59:57 rivo volumio[3104]: info: CoreStateMachine::pushState Dec 20 09:59:57 rivo volumio[3104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 20 09:59:57 rivo volumio[3104]: info: CoreCommandRouter::volumioPushState Dec 20 09:59:57 rivo volumio[3104]: info: CoreCommandRouter::volumioGetState Dec 20 09:59:57 rivo volumio[3104]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 20 09:59:57 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:57 rivo volumio[3104]: info: Signalling Playback active due to playback status change Dec 20 09:59:59 rivo volumio[3104]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 20 09:59:59 rivo volumio[3104]: Error: read ECONNRESET Dec 20 09:59:59 rivo volumio[3104]: at TCP.onStreamRead (internal/stream_base_commons.js:209:20) { Dec 20 09:59:59 rivo volumio[3104]: errno: -104, Dec 20 09:59:59 rivo volumio[3104]: code: 'ECONNRESET', Dec 20 09:59:59 rivo volumio[3104]: syscall: 'read' Dec 20 09:59:59 rivo volumio[3104]: } Dec 20 09:59:59 rivo volumio[3104]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 20 10:00:00 rivo sudo[19542]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-20 09:58 Dec 20 10:00:00 rivo sudo[19542]: 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="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 07:07:40 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="90457dc663650a5d2f936402ef6c7dc1"