-- Logs begin at Wed 2025-06-18 06:05:06 UTC, end at Wed 2025-06-18 08:18:53 UTC. -- Jun 18 08:17:00 zen-stream volumio[18454]: info: Jun 18 08:17:00 zen-stream volumio[18454]: ---------------------------- MPD announces system playlist update Jun 18 08:17:00 zen-stream volumio[18454]: info: Ignoring MPD Status Update Jun 18 08:17:00 zen-stream volumio[18454]: info: Jun 18 08:17:00 zen-stream volumio[18454]: ---------------------------- MPD announces state update: player Jun 18 08:17:00 zen-stream volumio[18454]: info: ControllerMpd::getState Jun 18 08:17:00 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand status Jun 18 08:17:00 zen-stream volumio[18454]: info: ------------------------------ 8ms Jun 18 08:17:00 zen-stream volumio[18454]: info: sendMpdCommand status took 4 milliseconds Jun 18 08:17:00 zen-stream volumio[18454]: verbose: ControllerMpd::parseState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:00 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 08:17:00 zen-stream volumio[18454]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 08:17:00 zen-stream volumio[18454]: verbose: ControllerMpd::parseTrackInfo Jun 18 08:17:00 zen-stream volumio[18454]: info: ControllerMpd::pushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::servicePushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:00 zen-stream volumio[18454]: verbose: STATE SERVICE {"status":"play","position":0,"seek":30177,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Stevie Wonder - I Just Called To Say I Love You","artist":"Smooth London","album":null,"uri":"https://media-ssl.musicradio.com/SmoothLondonMP3","trackType":""} Jun 18 08:17:00 zen-stream volumio[18454]: verbose: CURRENT POSITION 0 Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreStateMachine::syncState stateService play Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreStateMachine::syncState currentStatus play Jun 18 08:17:00 zen-stream volumio[18454]: info: Received an update from plugin. extracting info from payload Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:00 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:00 zen-stream volumio[18454]: info: ------------------------------ 106ms Jun 18 08:17:01 zen-stream volumio[18454]: info: Jun 18 08:17:01 zen-stream volumio[18454]: ---------------------------- MPD announces system playlist update Jun 18 08:17:01 zen-stream volumio[18454]: info: Ignoring MPD Status Update Jun 18 08:17:01 zen-stream volumio[18454]: info: Jun 18 08:17:01 zen-stream volumio[18454]: ---------------------------- MPD announces state update: player Jun 18 08:17:01 zen-stream volumio[18454]: info: ControllerMpd::getState Jun 18 08:17:01 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand status Jun 18 08:17:01 zen-stream volumio[18454]: info: ------------------------------ 7ms Jun 18 08:17:01 zen-stream volumio[18454]: info: sendMpdCommand status took 4 milliseconds Jun 18 08:17:01 zen-stream volumio[18454]: verbose: ControllerMpd::parseState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:01 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 08:17:01 zen-stream volumio[18454]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 08:17:01 zen-stream volumio[18454]: verbose: ControllerMpd::parseTrackInfo Jun 18 08:17:01 zen-stream volumio[18454]: info: ControllerMpd::pushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::servicePushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:01 zen-stream volumio[18454]: verbose: STATE SERVICE {"status":"play","position":0,"seek":31782,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Stevie Wonder - I Just Called To Say I Love You","artist":"Smooth London","album":null,"uri":"https://media-ssl.musicradio.com/SmoothLondonMP3","trackType":""} Jun 18 08:17:01 zen-stream volumio[18454]: verbose: CURRENT POSITION 0 Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreStateMachine::syncState stateService play Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreStateMachine::syncState currentStatus play Jun 18 08:17:01 zen-stream volumio[18454]: info: Received an update from plugin. extracting info from payload Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:01 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:01 zen-stream volumio[18454]: info: ------------------------------ 95ms Jun 18 08:17:04 zen-stream volumio[18454]: info: Jun 18 08:17:04 zen-stream volumio[18454]: ---------------------------- MPD announces system playlist update Jun 18 08:17:04 zen-stream volumio[18454]: info: Ignoring MPD Status Update Jun 18 08:17:04 zen-stream volumio[18454]: info: Jun 18 08:17:04 zen-stream volumio[18454]: ---------------------------- MPD announces state update: player Jun 18 08:17:04 zen-stream volumio[18454]: info: ControllerMpd::getState Jun 18 08:17:04 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand status Jun 18 08:17:04 zen-stream volumio[18454]: info: ------------------------------ 6ms Jun 18 08:17:04 zen-stream volumio[18454]: info: sendMpdCommand status took 3 milliseconds Jun 18 08:17:04 zen-stream volumio[18454]: verbose: ControllerMpd::parseState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:04 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 08:17:04 zen-stream volumio[18454]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 08:17:04 zen-stream volumio[18454]: verbose: ControllerMpd::parseTrackInfo Jun 18 08:17:04 zen-stream volumio[18454]: info: ControllerMpd::pushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::servicePushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:04 zen-stream volumio[18454]: verbose: STATE SERVICE {"status":"play","position":0,"seek":34078,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Stevie Wonder - I Just Called To Say I Love You","artist":"Smooth London","album":null,"uri":"https://media-ssl.musicradio.com/SmoothLondonMP3","trackType":""} Jun 18 08:17:04 zen-stream volumio[18454]: verbose: CURRENT POSITION 0 Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreStateMachine::syncState stateService play Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreStateMachine::syncState currentStatus play Jun 18 08:17:04 zen-stream volumio[18454]: info: Received an update from plugin. extracting info from payload Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:04 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:04 zen-stream volumio[18454]: info: ------------------------------ 92ms Jun 18 08:17:04 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:05 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:05 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:05 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:06 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:06 zen-stream volumio[18454]: info: ++++--++++ browseLibrary: {"uri":"music-library"} Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 18 08:17:06 zen-stream volumio[18454]: info: CURURI: music-library Jun 18 08:17:06 zen-stream volumio[18454]: error: Failed LSINFO: null Jun 18 08:17:06 zen-stream volumio[18454]: info: Preload queue cleared Jun 18 08:17:06 zen-stream volumio[18454]: info: Jun 18 08:17:06 zen-stream volumio[18454]: ---------------------------- MPD announces system playlist update Jun 18 08:17:06 zen-stream volumio[18454]: info: Ignoring MPD Status Update Jun 18 08:17:06 zen-stream volumio[18454]: info: Jun 18 08:17:06 zen-stream volumio[18454]: ---------------------------- MPD announces state update: player Jun 18 08:17:06 zen-stream volumio[18454]: info: ControllerMpd::getState Jun 18 08:17:06 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand status Jun 18 08:17:06 zen-stream volumio[18454]: info: ------------------------------ 7ms Jun 18 08:17:06 zen-stream volumio[18454]: info: sendMpdCommand status took 4 milliseconds Jun 18 08:17:06 zen-stream volumio[18454]: verbose: ControllerMpd::parseState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:06 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 08:17:06 zen-stream volumio[18454]: info: sendMpdCommand playlistinfo took 10 milliseconds Jun 18 08:17:06 zen-stream volumio[18454]: verbose: ControllerMpd::parseTrackInfo Jun 18 08:17:06 zen-stream volumio[18454]: info: ControllerMpd::pushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::servicePushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:06 zen-stream volumio[18454]: verbose: STATE SERVICE {"status":"play","position":0,"seek":36677,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Stevie Wonder - I Just Called To Say I Love You","artist":"Smooth London","album":null,"uri":"https://media-ssl.musicradio.com/SmoothLondonMP3","trackType":""} Jun 18 08:17:06 zen-stream volumio[18454]: verbose: CURRENT POSITION 0 Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreStateMachine::syncState stateService play Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreStateMachine::syncState currentStatus play Jun 18 08:17:06 zen-stream volumio[18454]: info: Received an update from plugin. extracting info from payload Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:06 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:06 zen-stream volumio[18454]: info: ------------------------------ 95ms Jun 18 08:17:06 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:07 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:07 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:08 zen-stream volumio[18454]: info: ++++--++++ browseLibrary: {"uri":"music-library"} Jun 18 08:17:08 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 18 08:17:08 zen-stream volumio[18454]: info: CURURI: music-library Jun 18 08:17:08 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:08 zen-stream volumio[18454]: error: Failed LSINFO: null Jun 18 08:17:08 zen-stream volumio[18454]: info: Preload queue cleared Jun 18 08:17:08 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:09 zen-stream volumio[18454]: info: Jun 18 08:17:09 zen-stream volumio[18454]: ---------------------------- MPD announces system playlist update Jun 18 08:17:09 zen-stream volumio[18454]: info: Ignoring MPD Status Update Jun 18 08:17:09 zen-stream volumio[18454]: info: Jun 18 08:17:09 zen-stream volumio[18454]: ---------------------------- MPD announces state update: player Jun 18 08:17:09 zen-stream volumio[18454]: info: ControllerMpd::getState Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand status Jun 18 08:17:09 zen-stream volumio[18454]: info: ------------------------------ 6ms Jun 18 08:17:09 zen-stream volumio[18454]: info: sendMpdCommand status took 3 milliseconds Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::parseState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 08:17:09 zen-stream volumio[18454]: info: sendMpdCommand playlistinfo took 11 milliseconds Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::parseTrackInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: ControllerMpd::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::servicePushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:09 zen-stream volumio[18454]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39185,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Stevie Wonder - I Just Called To Say I Love You","artist":"Smooth London","album":null,"uri":"https://media-ssl.musicradio.com/SmoothLondonMP3","trackType":""} Jun 18 08:17:09 zen-stream volumio[18454]: verbose: CURRENT POSITION 0 Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::syncState stateService play Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::syncState currentStatus play Jun 18 08:17:09 zen-stream volumio[18454]: info: Received an update from plugin. extracting info from payload Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: ------------------------------ 101ms Jun 18 08:17:09 zen-stream volumio[18454]: info: ++++--++++ stop Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioStop Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::stop Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::stPlaybackTimer Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::updateTrackBlock Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrackBlock Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::serviceStop Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::serviceStop Jun 18 08:17:09 zen-stream volumio[18454]: info: [1750234629337] ControllerWebradio::stop Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand stop Jun 18 08:17:09 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:09 zen-stream volumio[18454]: info: Jun 18 08:17:09 zen-stream volumio[18454]: ---------------------------- MPD announces state update: player Jun 18 08:17:09 zen-stream volumio[18454]: info: sendMpdCommand stop took 35 milliseconds Jun 18 08:17:09 zen-stream volumio[18454]: info: ControllerMpd::getState Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand status Jun 18 08:17:09 zen-stream volumio[18454]: info: sendMpdCommand status took 6 milliseconds Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::parseState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetState Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 18 08:17:09 zen-stream volumio[18454]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 18 08:17:09 zen-stream volumio[18454]: verbose: ControllerMpd::parseTrackInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: ControllerMpd::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::servicePushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:09 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:09 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:09 zen-stream volumio[18454]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jun 18 08:17:09 zen-stream volumio[18454]: info: ------------------------------ 46ms Jun 18 08:17:09 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:09 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:10 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:10 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:10 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:10 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:11 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:12 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.222 [4867.4870] INFO SampleApp: API endpoint invoked: get-connect-info Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] INFO SampleApp: API endpoint invoked: connect-to-qconnect Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: Session ID: 8dae6a3b-d300-4493-aeb0-18c7242bdee2 Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: JWT API: Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: Endpoint: https://www.qobuz.com/api.json/0.2 Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: JWT: eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiIsImtpZCI6ImRWN3hqanE2TFljdXpGYWdyT1pkMWxuSEoyMVhRMk5UIn0.eyJpYXQiOjE3NTAyMzQ2MzMsImV4cCI6MTc1MDIzODIzMywiaXNzIjoiUW9idXogQVBJIiwicXVpZCI6MjY3OTE1NywicWFpZCI6IjY3OTMxODk3MiJ9.ERQKLsY2v3z_dMHu0vbmEdUdKs2X8hJ3zNKYoJHNkkE Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: Exp: 1750238233 Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: JWT QConnect: Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: Endpoint: wss://qws-us-prod.qobuz.com/ws Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: JWT: eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3NTAyMzQ2MzMsImV4cCI6MTc1MDIzODIzMywiaXNzIjoiUW9idXogQVBJIiwicXVpZCI6MjY3OTE1NywicWFpZCI6IjY3OTMxODk3MiJ9.AQsukA5IKqf2RoYEO2iZF5Bg2sFz_hvpwOXeOdC_BY0 Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: Exp: 1750238233 Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4870] DEBUG SampleApp: Become Active: true Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4867] DEBUG RendererActivationCommandSequencer: [0xab2fa9a0]: Enqueuing command: Deactivate + Disconnect Renderer Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.623 [4867.4867] DEBUG RendererActivationCommandSequencer: [0xab2fa9a0]: Enqueuing command: Connect Renderer Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Executing command: Deactivate + Disconnect Renderer Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationCommandSequencer: [0xab2fa9a0]: Confirming command: Deactivate + Disconnect Renderer Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Executing command: Connect Renderer Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Updating endpoints Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] INFO EndpointManager: [0xab2f9918]: Updating API endpoint Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] TRACE EndpointManager: [0xab2f9928]: API endpoint's token state changed: Invalid -> Valid Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG EndpointManager: [0xab2f9928]: API endpoint's token will be refreshed in 3540 seconds Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG EndpointManager: [0xab2f9928]: API endpoint's token will expire in 3600 seconds Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] INFO EndpointManager: [0xab2f9918]: Updating QConnect endpoint Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] TRACE EndpointManager: [0xab2f9a10]: QConnect endpoint's token state changed: Invalid -> Valid Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG EndpointManager: [0xab2f9a10]: QConnect endpoint's token will be refreshed in 3540 seconds Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG EndpointManager: [0xab2f9a10]: QConnect endpoint's token will expire in 3600 seconds Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Making the renderer active Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] INFO ActiveStateManager: [0xab2f8930]: Setting new active state: active Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Starting playback session maintenance Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] INFO PlaybackSessionManager: [0xab2f9d08]: Starting playback session maintenance Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] TRACE PlaybackSessionManager: [0xab2f9d08]: Not refreshing playback session because it's not needed Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Connecting to the server Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] INFO CloudClient: [0xab2fa578]: Connecting to the cloud Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG NetworkActivityTracker: [0xab2f89a0]: Network activity started Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.624 [4867.4867] DEBUG WebsocketClient: [0xab635cd8]: Creating Websocket client Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.625 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Configuring connection Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.658 [4867.4867] TRACE PlaybackSessionManager: [0xab2f9d08]: Not refreshing playback session because it's not needed Jun 18 08:17:13 zen-stream play[4850]: 20250618 08:17:13.659 [4867.4867] INFO SampleApp: Renderer is now active Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.901 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Connected, server protocols: default Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO CloudClient: [0xab2fa578]: Connection established Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] DEBUG QwspMessageSender: [0xab557f80]: Creating QWSP Message Sender Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] DEBUG QConnectMessageSender: [0xab558608]: Creating QConnect Message Sender Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Authenticate message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Token: eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3NTAyMzQ2MzMsImV4cCI6MTc1MDIzODIzMywiaXNzIjoiUW9idXogQVBJIiwicXVpZCI6MjY3OTE1NywicWFpZCI6IjY3OTMxODk3MiJ9.AQsukA5IKqf2RoYEO2iZF5Bg2sFz_hvpwOXeOdC_BY0 Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Subscribe message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending JoinSession message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Reason: Controller Request Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Active: true Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Session UUID: 8dae6a3b-d300-4493-aeb0-18c7242bdee2 Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 100 Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeMuted message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Muted: false Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending MaxAudioQualityChanged message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.902 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Max quality: HIRES_L3 Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.903 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.903 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.903 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.903 [4867.4867] DEBUG RendererActivationController: [0xab2fa8f8]: Connection to QConnect server established Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.903 [4867.4867] TRACE RendererActivationController: [0xab2fa8f8]: State changed: Inactive (Disconnected) -> Active Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.903 [4867.4867] DEBUG RendererActivationCommandSequencer: [0xab2fa9a0]: Confirming command: Connect Renderer Jun 18 08:17:14 zen-stream play[4850]: 20250618 08:17:14.904 [4867.4867] DEBUG UserInactivityManager: [0xab2fad38]: Renderer is active but not playing, will deactivate in 3600s Jun 18 08:17:15 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.155 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 129 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetActive message: active Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetState message: Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Playing state: Paused Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Playback position: 94000 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Queue version: 1.1 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Current track: TID: 312623294, QID: 1, Context UUID: 040f5acb-b489-4265-9c1f-bfbf615d2bfa Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Next track: TID: 312623295, QID: 2, Context UUID: 040f5acb-b489-4265-9c1f-bfbf615d2bfa Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO MediaEngine: [0xab2f9fa0]: Stopping playback, clearing tracks Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Enqueuing command: Stop Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Enqueuing command: SetCurrentTrack Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Enqueuing command: SetNextTrack Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO MediaEngine: [0xab2f9fa0]: Initiating playback Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Enqueuing command: InitiatePlayback Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Executing command: Stop Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Confirming command: Stop Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetLoopMode message: All Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO PlaybackControlsManager: [0xab2fa378]: Setting new loop mode: All Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Executing command: SetCurrentTrack Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO MediaEngine: [0xab2f9fa0]: Setting current track: 312623294, initial offset: 94000ms Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Clearing all streams Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: New stream: 31 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] DEBUG PlaybackUrlFetcher: [0xab3dbb28]: Creating Playback URL Fetcher for track: 312623294 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.156 [4867.4867] INFO HttpDownloader: [0xab875020]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=9cf91f7af57d3ca0576138b5d9143983&request_ts=1750234635&track_id=312623294 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG MetadataFetcher: [0xab453788]: Creating Metadata Fetcher for track: 312623294 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO HttpDownloader: [0xab7e03f8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=312623294 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG AudioStreamInfoFetcher: [0xab3a3248]: Creating Audio Stream Info Fetcher for track: 312623294 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO HttpDownloader: [0xab3a3308]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=27419cfa44901b085d55d75e3de98b4f&request_ts=1750234635&track_id=312623294 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 31]: Running audio stream Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Confirming command: SetCurrentTrack Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetShuffleMode message: disabled Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO PlaybackControlsManager: [0xab2fa378]: Setting new shuffle mode: disabled Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Current stream changed state: Nonexistent -> Created Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Executing command: SetNextTrack Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO MediaEngine: [0xab2f9fa0]: Setting next track: 312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: New stream: 32 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG PlaybackUrlFetcher: [0xab864860]: Creating Playback URL Fetcher for track: 312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO HttpDownloader: [0xab8648e0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=42fa1826ca31f0474c6c273a074635cd&request_ts=1750234635&track_id=312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG MetadataFetcher: [0xab686708]: Creating Metadata Fetcher for track: 312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO HttpDownloader: [0xab686790]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG AudioStreamInfoFetcher: [0xab8649a8]: Creating Audio Stream Info Fetcher for track: 312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] INFO HttpDownloader: [0xab8e5c18]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=0b979a0f846f90ed32ac8f98ffeee632&request_ts=1750234635&track_id=312623295 Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.157 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Confirming command: SetNextTrack Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.160 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Next stream changed state: Nonexistent -> Created Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.160 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Executing command: InitiatePlayback Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.160 [4867.4867] INFO MediaEngine: [0xab2f9fa0]: Waiting for current stream to start before starting audio renderer Jun 18 08:17:15 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:15 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:15 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.926 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 32]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2679157&eid=312623295&fmt=7&profile=raw&app_id=679318972&cid=2334679&etsp=1750238235&hmac=qzpt8Y_0_cI8BmZT7RxB-pS5KUY Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.994 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 32]: stream information have been fetched Jun 18 08:17:15 zen-stream play[4850]: 20250618 08:17:15.994 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Next stream changed state: Created -> Info Retrieved Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] TRACE MetadataFetcher: [0xab686708]: Track 312623295 doesn't have a valid version field Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] TRACE MetadataFetcher: [0xab686708]: Track 312623295 doesn't have a valid work field Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] TRACE MetadataFetcher: [0xab686708]: Track 312623295 doesn't have a valid album version field Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 32]: Metadata became available: Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Title: Silver Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Artist: Sea Lemon Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Album: Diving For A Prize Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Album art URL: https://static.qobuz.com/images/covers/gb/5b/q1mca41oo5bgb_600.jpg Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.026 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 31]: stream information have been fetched Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] INFO UrlAudioSource: [0xab6863c0]: Starting URL audio source, initial position: 94000ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2679157&eid=312623294&fmt=7&profile=raw&app_id=679318972&cid=2334679&etsp=1750238235&hmac=uhpxlo7ogeLCvbWzqIW7vgciuuQ Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] TRACE AudioSource: [0xab6863c0]: State changed: Idle -> Running Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] DEBUG Ringbuffer: [0xab837200]: Creating Audio Ringbuffer Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] INFO ContentFetcher: [0xab301068]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2679157&eid=312623294&fmt=7&profile=raw&app_id=679318972&cid=2334679&etsp=1750238235&hmac=uhpxlo7ogeLCvbWzqIW7vgciuuQ, offset: 0 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 31]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2679157&eid=312623294&fmt=7&profile=raw&app_id=679318972&cid=2334679&etsp=1750238235&hmac=uhpxlo7ogeLCvbWzqIW7vgciuuQ Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Current stream changed state: Created -> Info Retrieved Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Current stream changed state: Info Retrieved -> Running Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] INFO AudioRenderer: [0xab2fa1c0]: Starting audio renderer, initial playback state: Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: State changed: Stopped -> Initiating (Paused) Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] INFO SampleApp: [Stream 31]: New audio stream (starting from 94000ms) Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Audio renderer state changed: Stopped -> Initiating (Paused) Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] INFO SampleApp: Initiating playback, initial state: Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] DEBUG AudioRenderer: [0xab2fa1c0]: Playback initiated (paused state) Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.027 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: State changed: Initiating (Paused) -> Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Audio renderer state changed: Initiating (Paused) -> Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE MediaEngine: [0xab2f9fa0]: State changed: Stopped -> Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Confirming command: InitiatePlayback Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] INFO SampleApp: Playback state changed: Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] ERROR SampleApp: Unable to get buffered frame count from ALSA audio sink: device is not open Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 94000 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Paused Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 94000 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending FileAudioQualityChanged message Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Sample rate: 96000 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.028 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Bit depth: 24 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Channel count: 2 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Audio quality: HIRES_L1 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending DeviceAudioQualityChanged message Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Sample rate: 96000 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Bit depth: 24 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.029 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Channel count: 2 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.030 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.030 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.030 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.030 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 94000ms Jun 18 08:17:16 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.063 [4867.4867] TRACE MetadataFetcher: [0xab453788]: Track 312623294 doesn't have a valid version field Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.063 [4867.4867] TRACE MetadataFetcher: [0xab453788]: Track 312623294 doesn't have a valid work field Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.063 [4867.4867] TRACE MetadataFetcher: [0xab453788]: Track 312623294 doesn't have a valid album version field Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 31]: Metadata became available: Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Title: Stay Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Artist: Sea Lemon Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Album: Diving For A Prize Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: Album art URL: https://static.qobuz.com/images/covers/gb/5b/q1mca41oo5bgb_600.jpg Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO SampleApp: [Stream 31]: Stream metadata became available: Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO SampleApp: Title: Stay Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO SampleApp: Artist: Sea Lemon Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO SampleApp: Album: Diving For A Prize Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.064 [4867.4867] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/gb/5b/q1mca41oo5bgb_600.jpg Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.663 [4867.4867] INFO UrlAudioSource: [0xab6863c0]: Content info extracted Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.664 [4867.4867] INFO UrlAudioSource: [0xab6863c0]: Size: 70694604 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.670 [4867.20638] INFO AudioDecoder: [0xab6e3680]: Stream info: Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.670 [4867.20638] INFO AudioDecoder: [0xab6e3680]: Total samples: 18457600 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.670 [4867.20638] INFO AudioDecoder: [0xab6e3680]: Sample rate: 96000 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.670 [4867.20638] INFO AudioDecoder: [0xab6e3680]: Channel count: 2 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.670 [4867.20638] INFO AudioDecoder: [0xab6e3680]: Bits per sample: 24 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.670 [4867.20638] INFO AudioDecoder: [0xab6e3680]: Duration: 192266 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.671 [4867.4867] INFO UrlAudioSource: [0xab6863c0]: Audio properties have changed Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.671 [4867.4867] INFO UrlAudioSource: [0xab6863c0]: Seeking input stream to byte offset: 34255217 Jun 18 08:17:16 zen-stream play[4850]: 20250618 08:17:16.671 [4867.4867] INFO ContentFetcher: [0xab301068]: Adjusting download offset to: 34255217 Jun 18 08:17:16 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:17 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:17 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:18 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.823 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetState message: Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Playing state: Playing Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Playback position: Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Queue version: Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Current track: Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Next track: Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO MediaEngine: [0xab2f9fa0]: Resuming playback Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Enqueuing command: Resume Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Executing command: Resume Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] INFO AudioRenderer: [0xab2fa1c0]: Resuming audio renderer Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: State changed: Paused -> Resuming Jun 18 08:17:19 zen-stream play[4850]: 20250618 08:17:19.824 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Audio renderer state changed: Paused -> Resuming Jun 18 08:17:19 zen-stream volumio[18454]: info: Jun 18 08:17:19 zen-stream volumio[18454]: ---------------------------- Client requests Start Qobuz PlaybackRoutine Jun 18 08:17:19 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: qobuz_connect , startQobuzPlayback Jun 18 08:17:19 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface qobuz_connect Jun 18 08:17:20 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:20 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:20 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:20 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:20 zen-stream kernel: wm8804 0-003b: wm8804_hw_params rate: 0x17700 format: 0x6 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.830 [4867.4867] TRACE SampleApp: ALSA PCM's descriptor count: 1 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.830 [4867.4867] INFO SampleApp: Resuming playback Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.833 [4867.4867] DEBUG AudioRenderer: [0xab2fa1c0]: Transition to playing state (resume) has been acknowledged Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.833 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: State changed: Resuming -> Playing Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.833 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Audio renderer state changed: Resuming -> Playing Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.833 [4867.4867] TRACE MediaEngine: [0xab2f9fa0]: State changed: Paused -> Playing Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.833 [4867.4867] DEBUG MediaEngineCommandSequencer: [0xab2fa318]: Confirming command: Resume Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.834 [4867.4867] DEBUG PlaybackProgressManager: [0xab2fa218]: Audio playback started, time until playback gets near the end: 88265ms Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] INFO SampleApp: Playback state changed: Playing Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 94002 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] INFO StreamingEventReporter: [0xab2faaf8]: Reporting streaming started event Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE StreamingEventReporter: [0xab2faaf8]: Track ID: 312623294 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE StreamingEventReporter: [0xab2faaf8]: Start position: 94002ms Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE StreamingEventReporter: [0xab2faaf8]: Context UUID: 040f5acb-b489-4265-9c1f-bfbf615d2bfa Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE StreamingEventReporter: [0xab2faaf8]: Blob ID: 100000.Rf2eO_YHHDsKejFLtaXKuPg5Mw-nGOEBb4fRjoxam3ZaH1VNz9CWRWlfF1JXdxVi.PzH-4z3O4gtaTpEjQvqRlTmYHqU Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] DEBUG StreamingEventReporter: [0xab2faaf8]: Sending streaming reports Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] INFO HttpDownloader: [0xab2fab50]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 94002 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 94002 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.835 [4867.4867] DEBUG UserInactivityManager: [0xab2fad38]: Renderer is actively playing Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.842 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.842 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.842 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.843 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 94001ms Jun 18 08:17:20 zen-stream play[4850]: 20250618 08:17:20.844 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 94002ms Jun 18 08:17:20 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:21 zen-stream play[4850]: 20250618 08:17:21.283 [4867.4867] DEBUG StreamingEventReporter: [0xab2faaf8]: Streaming report submitted successfully Jun 18 08:17:25 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:25 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:25 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:30 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:30 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:30 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:30 zen-stream volumio[18454]: info: ++++--++++ volume: 90 Jun 18 08:17:30 zen-stream volumio[18454]: info: VolumeController::SetAlsaVolume90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.650 [4867.4867] TRACE SampleApp: Volume changed: 90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.650 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.650 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:17:30 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:30 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:30 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:30 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:30 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:30 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] INFO SampleApp: Playback volume changed: 90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] TRACE SampleApp: Setting volume: 90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 90 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.800 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 104001 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 104001 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:30 zen-stream play[4850]: 20250618 08:17:30.836 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 104001ms Jun 18 08:17:31 zen-stream volumio[18454]: info: ++++--++++ volume: 70 Jun 18 08:17:31 zen-stream volumio[18454]: info: VolumeController::SetAlsaVolume70 Jun 18 08:17:31 zen-stream play[4850]: 20250618 08:17:31.933 [4867.4867] TRACE SampleApp: Volume changed: 70 Jun 18 08:17:31 zen-stream play[4850]: 20250618 08:17:31.933 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 70 Jun 18 08:17:31 zen-stream play[4850]: 20250618 08:17:31.933 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:17:31 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Jun 18 08:17:31 zen-stream volumio[18454]: info: CoreStateMachine::pushState Jun 18 08:17:31 zen-stream volumio[18454]: info: CorePlayQueue::getTrack 0 Jun 18 08:17:31 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:31 zen-stream volumio[18454]: info: CoreCommandRouter::volumioPushState Jun 18 08:17:31 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.082 [4867.4867] INFO SampleApp: Playback volume changed: 70 Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] TRACE SampleApp: Setting volume: 70 Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 70 Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 70 Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:32 zen-stream play[4850]: 20250618 08:17:32.083 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:33 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.625 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.626 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.626 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.776 [4867.4867] INFO SampleApp: Playback volume changed: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.776 [4867.4867] TRACE SampleApp: Setting volume: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.776 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.776 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.776 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.776 [4867.4867] TRACE SampleApp: Volume changed: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.777 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 71 Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.777 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.777 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.777 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:33 zen-stream play[4850]: 20250618 08:17:33.777 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:33 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.230 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.231 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.231 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.381 [4867.4867] INFO SampleApp: Playback volume changed: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.381 [4867.4867] TRACE SampleApp: Setting volume: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.381 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.381 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.381 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.381 [4867.4867] TRACE SampleApp: Volume changed: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.382 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.382 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.382 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.382 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.382 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.449 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.449 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 100 Jun 18 08:17:34 zen-stream play[4850]: 20250618 08:17:34.449 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 100 Jun 18 08:17:35 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:35 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:35 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:35 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:35 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.144 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.145 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.145 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.294 [4867.4867] INFO SampleApp: Playback volume changed: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] TRACE SampleApp: Setting volume: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] TRACE SampleApp: Volume changed: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 99 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.295 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.582 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.583 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 23 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.583 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 23 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.733 [4867.4867] INFO SampleApp: Playback volume changed: 23 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.733 [4867.4867] TRACE SampleApp: Setting volume: 23 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.733 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 23 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.733 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.733 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 23 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.734 [4867.4867] TRACE SampleApp: Volume changed: 22 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.734 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 22 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.734 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.734 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.734 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.734 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] INFO SampleApp: Playback volume changed: 22 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] TRACE SampleApp: Setting volume: 22 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 22 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 22 Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:36 zen-stream play[4850]: 20250618 08:17:36.884 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:37 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:38 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:38 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:38 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:40 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:40 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:40 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.834 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 114001 Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.837 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.837 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.838 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.838 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 114001 Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.839 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.840 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.840 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.841 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.841 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.841 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.841 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:40 zen-stream play[4850]: 20250618 08:17:40.842 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 114001ms Jun 18 08:17:45 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:45 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:45 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:50 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 124002 Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 124002 Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.836 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.836 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.836 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:17:50 zen-stream play[4850]: 20250618 08:17:50.837 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 124002ms Jun 18 08:17:51 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:51 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:55 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:17:56 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:17:56 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:17:58 zen-stream volumio[18454]: info: Discovery: A device disappeared from network Jun 18 08:17:58 zen-stream volumio[18454]: info: Discovery: Device ifi-zen-eriri disappeared from network Jun 18 08:17:58 zen-stream volumio[18454]: info: Discovery: Disconnected from remote: 192.168.1.209 Jun 18 08:17:58 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:17:59 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 134002 Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.837 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.838 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.839 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.839 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 134002 Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.840 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.840 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.841 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.841 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.842 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.843 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.843 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:00 zen-stream play[4850]: 20250618 08:18:00.844 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 134002ms Jun 18 08:18:00 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:01 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:01 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:03 zen-stream volumio[18454]: info: Discovery: adding fe8a337a-96b8-437e-8019-52a130822221 Jun 18 08:18:03 zen-stream volumio[18454]: info: Discovery: Found device iFi-zen-eriri Jun 18 08:18:03 zen-stream volumio[18454]: info: Discovery: Connecting to remote: 192.168.1.209 Jun 18 08:18:04 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:18:04 zen-stream volumio[18454]: info: Discovery: Connected to remote: 192.168.1.209 Jun 18 08:18:04 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:18:04 zen-stream volumio[18454]: error: Could not retrieve plugin audio_interface multiroom Jun 18 08:18:06 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:06 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:06 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.081 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.081 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 33 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.081 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 33 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] INFO SampleApp: Playback volume changed: 33 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] TRACE SampleApp: Setting volume: 33 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 33 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 33 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] TRACE SampleApp: Volume changed: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.231 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.232 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.232 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.232 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.381 [4867.4867] INFO SampleApp: Playback volume changed: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] TRACE SampleApp: Setting volume: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.383 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.759 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.760 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 32 Jun 18 08:18:08 zen-stream play[4850]: 20250618 08:18:08.760 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 32 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.207 [4867.4867] TRACE WebsocketClient: [0xab635cd8]: Binary data received, size: 40 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.208 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Received SetVolume message, volume: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.208 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.357 [4867.4867] INFO SampleApp: Playback volume changed: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.357 [4867.4867] TRACE SampleApp: Setting volume: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Volume changed: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending VolumeChanged message Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Volume: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] TRACE SampleApp: Volume changed: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] INFO VolumeManager: [0xab2fa408]: Setting new playback volume: 100 Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] ERROR SampleApp: Unable to get ALSA volume element's mute state: Invalid argument (-22) Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:09 zen-stream play[4850]: 20250618 08:18:09.358 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 144002 Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 144002 Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:10 zen-stream play[4850]: 20250618 08:18:10.836 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 144002ms Jun 18 08:18:11 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:11 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:11 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:16 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:16 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:16 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.834 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 154002 Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.834 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 154002 Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:20 zen-stream play[4850]: 20250618 08:18:20.835 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 154002ms Jun 18 08:18:21 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:21 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:21 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:26 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:26 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:26 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:29 zen-stream play[4850]: 20250618 08:18:29.445 [4867.4867] INFO PlaybackSessionManager: [0xab2f9d08]: Playback session needs refreshing Jun 18 08:18:29 zen-stream play[4850]: 20250618 08:18:29.445 [4867.4867] DEBUG PlaybackSessionManager: [0xab2f9d08]: Refreshing playback session Jun 18 08:18:29 zen-stream play[4850]: 20250618 08:18:29.446 [4867.4867] INFO HttpDownloader: [0xab2f9ef8]: Downloading content from: https://www.qobuz.com/api.json/0.2/session/start Jun 18 08:18:29 zen-stream play[4850]: 20250618 08:18:29.819 [4867.4867] INFO PlaybackSessionManager: [0xab2f9d08]: Playback session has been refreshed Jun 18 08:18:29 zen-stream play[4850]: 20250618 08:18:29.819 [4867.4867] DEBUG PlaybackSessionManager: [0xab2f9d08]: Playback session will be refreshed in 3000 seconds Jun 18 08:18:29 zen-stream play[4850]: 20250618 08:18:29.819 [4867.4867] DEBUG PlaybackSessionManager: [0xab2f9d08]: Playback session will expire in 3600 seconds Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 164003 Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 164003 Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.835 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:30 zen-stream play[4850]: 20250618 08:18:30.836 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 164003ms Jun 18 08:18:31 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:31 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:31 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:36 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 174004 Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 174004 Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.837 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.837 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.837 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:40 zen-stream play[4850]: 20250618 08:18:40.837 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 174004ms Jun 18 08:18:43 zen-stream volumio[18454]: info: ++++--++++ getMenuItems Jun 18 08:18:45 zen-stream volumio[18454]: info: ++++--++++ getUiConfig: {"page":"miscellanea/my_music"} Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 18 08:18:45 zen-stream volumio[18454]: error: Could not retrieve plugin music_service streaming_services Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetBrowseSources Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetBrowseSources Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::volumioGetBrowseSources Jun 18 08:18:45 zen-stream volumio[18454]: info: ++++--++++ getMyCollectionStats: null Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 18 08:18:45 zen-stream volumio[18454]: info: ++++--++++ getListShares: null Jun 18 08:18:45 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 18 08:18:45 zen-stream volumio[18454]: info: ++++--++++ getMyMusicPlugins Jun 18 08:18:47 zen-stream volumio[18454]: info: ++++--++++ getNetworkSharesDiscovery Jun 18 08:18:47 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jun 18 08:18:47 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jun 18 08:18:47 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:47 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:48 zen-stream systemd[1]: Starting Internet Detect for iFi Streamer... Jun 18 08:18:48 zen-stream systemd[1]: ifi-system-internet.service: Succeeded. Jun 18 08:18:48 zen-stream systemd[1]: Started Internet Detect for iFi Streamer. Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.101 [4867.4867] DEBUG AudioRenderer: [0xab2fa1c0]: Playback is nearly finished Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.101 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Playback is nearly finished Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.101 [4867.4867] INFO AudioStreamManager: [0xab2fa088]: [Stream 32]: Running audio stream Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.101 [4867.4867] INFO UrlAudioSource: [0xab4837b0]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2679157&eid=312623295&fmt=7&profile=raw&app_id=679318972&cid=2334679&etsp=1750238235&hmac=qzpt8Y_0_cI8BmZT7RxB-pS5KUY Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.101 [4867.4867] TRACE AudioSource: [0xab4837b0]: State changed: Idle -> Running Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.101 [4867.4867] DEBUG Ringbuffer: [0xab878e48]: Creating Audio Ringbuffer Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.102 [4867.4867] INFO ContentFetcher: [0xab7a7e10]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2679157&eid=312623295&fmt=7&profile=raw&app_id=679318972&cid=2334679&etsp=1750238235&hmac=qzpt8Y_0_cI8BmZT7RxB-pS5KUY, offset: 0 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.102 [4867.4867] DEBUG MediaEngine: [0xab2f9fa0]: Next stream changed state: Info Retrieved -> Running Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.103 [4867.4867] INFO SampleApp: [Stream 32]: New audio stream (starting from 0ms) Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.103 [4867.4867] INFO SampleApp: [Stream 32]: Stream metadata became available: Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.103 [4867.4867] INFO SampleApp: Title: Silver Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.103 [4867.4867] INFO SampleApp: Artist: Sea Lemon Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.103 [4867.4867] INFO SampleApp: Album: Diving For A Prize Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.103 [4867.4867] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/gb/5b/q1mca41oo5bgb_600.jpg Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.916 [4867.4867] INFO UrlAudioSource: [0xab4837b0]: Content info extracted Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.916 [4867.4867] INFO UrlAudioSource: [0xab4837b0]: Size: 66505630 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.926 [4867.22667] INFO AudioDecoder: [0xab5dbba0]: Stream info: Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.927 [4867.22667] INFO AudioDecoder: [0xab5dbba0]: Total samples: 18146560 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.929 [4867.22667] INFO AudioDecoder: [0xab5dbba0]: Sample rate: 96000 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.930 [4867.22667] INFO AudioDecoder: [0xab5dbba0]: Channel count: 2 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.931 [4867.22667] INFO AudioDecoder: [0xab5dbba0]: Bits per sample: 24 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.934 [4867.22667] INFO AudioDecoder: [0xab5dbba0]: Duration: 189026 Jun 18 08:18:49 zen-stream play[4850]: 20250618 08:18:49.934 [4867.4867] INFO UrlAudioSource: [0xab4837b0]: Audio properties have changed Jun 18 08:18:49 zen-stream volumio[18454]: info: ++++--++++ getMyCollectionStats: null Jun 18 08:18:49 zen-stream volumio[18454]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.835 [4867.4867] TRACE AudioRenderer: [0xab2fa1c0]: Playback position: 184004 Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.835 [4867.4867] INFO ProtocolHandler: [0xab2fa6e0]: Need to send state update Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] INFO QConnectMessageSender: [0xab558608]: Sending StateUpdated message Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Playback state: Playing Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current position: 184004 Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Duration: 192266 Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Queue version: 1.1 Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Current queue item ID: 1 Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QConnectMessageSender: [0xab558608]: Next queue item ID: 2 Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] INFO QwspMessageSender: [0xab557f80]: Sending Payload message Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Protocol: QConnect Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE QwspMessageSender: [0xab557f80]: Channel: Backend Jun 18 08:18:50 zen-stream play[4850]: 20250618 08:18:50.836 [4867.4867] TRACE PlaybackPositionEstimator: [0xab2fac70]: Synced playback position: 184004ms Jun 18 08:18:52 zen-stream volumio[18454]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 18 08:18:52 zen-stream volumio[18454]: Error: dns service error: unknown Jun 18 08:18:52 zen-stream volumio[18454]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Jun 18 08:18:52 zen-stream volumio[18454]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Jun 18 08:18:52 zen-stream volumio[18454]: errorCode: -65537 Jun 18 08:18:52 zen-stream volumio[18454]: } Jun 18 08:18:52 zen-stream volumio[18454]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 18 08:18:53 zen-stream sudo[22774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-18 08:17 Jun 18 08:18:53 zen-stream sudo[22774]: 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="1aa86d140f52e6978b55808c200d7f336afa9f78" VOLUMIO_FE_VERSION="0548e367fe44b194ccf1306c8af35deb040eccd2" VOLUMIO_FE3_VERSION="c63cc070c36379a8d79dc0d7d4a24908bebc2472" VOLUMIO_BE_VERSION="64dfbad964d654fe0e7d7d53305e712ecad248a1" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="ifi" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="2025年 06月 17日 星期二 16:39:50 CST" VOLUMIO_VERSION="0.00.1.01" VOLUMIO_HARDWARE="zen-stream3" VOLUMIO_DEVICENAME="ZEN Stream3" VOLUMIO_HASH="727c66af336dfbcf9f387633fda0970b"