Oct 14 16:39:00 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::ClearQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::stPlaybackTimer Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 6 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 6 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::serviceStop Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 6 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::serviceStop Oct 14 16:39:00 rivoplus volumio[26902]: info: [1791985140687] ControllerQobuz::stop Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::stop Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::clearPlayQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::addQueueItems Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::addQueueItems Oct 14 16:39:00 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/437417702 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/437417702 Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.691+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.692+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/19640484 title="Mood Indigo" Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPlay Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::play index 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::addQueueItems Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::addQueueItems Oct 14 16:39:00 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/440879153 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/440879153 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/444927822 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/444927822 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/437452757 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/437452757 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/446903513 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/446903513 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/429026697 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/429026697 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/448990359 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/448990359 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/439445075 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/439445075 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/442642367 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/442642367 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/443104633 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/443104633 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/436002220 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/436002220 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/431651081 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/431651081 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/417946382 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/417946382 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/444944359 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/444944359 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/438879991 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/438879991 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/418693792 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/418693792 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/426882827 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/426882827 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/412981431 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/412981431 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/416105033 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/416105033 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/421781887 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/421781887 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/452162253 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/452162253 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/414532675 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/414532675 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/442635358 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/442635358 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/450036400 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/450036400 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/435200889 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/435200889 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/441180048 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/441180048 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/447827808 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/447827808 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/418109267 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/418109267 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/448031663 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/448031663 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/445391382 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/445391382 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/450732372 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/450732372 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/445808534 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/445808534 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/438725809 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/438725809 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/419617471 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/419617471 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/444749342 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/444749342 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/429473719 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/429473719 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/423475184 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/423475184 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/414425748 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/414425748 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/433293932 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/433293932 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/434444429 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/434444429 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/408615380 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/408615380 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/395977940 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/395977940 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/392889657 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/392889657 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/403169418 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/403169418 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/401765782 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/401765782 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/408605525 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/408605525 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/358918103 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/358918103 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/407834844 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/407834844 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/397944493 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/397944493 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/404097129 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/404097129 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/388521550 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/388521550 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/406607763 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/406607763 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/400934289 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/400934289 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/398854700 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/398854700 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/409943356 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/409943356 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/412048645 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/412048645 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/393088444 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/393088444 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/404457206 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/404457206 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/404127732 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/404127732 Oct 14 16:39:00 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/411338004 Oct 14 16:39:00 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/411338004 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::play index undefined Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::startPlaybackTimer Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: [1791985140835] ControllerQobuz::clearAddPlayTrack Oct 14 16:39:00 rivoplus volumio[26902]: info: Oct 14 16:39:00 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand stop took 196 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:00 rivoplus volumio[26902]: info: Oct 14 16:39:00 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:00 rivoplus volumio[26902]: info: Oct 14 16:39:00 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand status took 12 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand status took 10 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand status took 9 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:00 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:39:00 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:00 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:00 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:39:00 rivoplus volumio[26902]: info: ------------------------------ 46ms Oct 14 16:39:00 rivoplus volumio[26902]: info: ------------------------------ 45ms Oct 14 16:39:00 rivoplus volumio[26902]: info: ------------------------------ 45ms Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.930+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.930+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.931+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.931+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.931+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:39:00 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:00.931+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:01 rivoplus volumio[26902]: info: getStreamUrl took 169 milliseconds Oct 14 16:39:01 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:39:01 rivoplus volumio[26902]: info: sendMpdCommand stop took 1 milliseconds Oct 14 16:39:01 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand clear Oct 14 16:39:01 rivoplus volumio[26902]: info: Oct 14 16:39:01 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:01 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:01 rivoplus volumio[26902]: info: sendMpdCommand clear took 3 milliseconds Oct 14 16:39:01 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ" Oct 14 16:39:01 rivoplus volumio[26902]: info: Oct 14 16:39:01 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:01 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:01 rivoplus volumio[26902]: info: Oct 14 16:39:01 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:01 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:01 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:01 rivoplus volumio[26902]: info: ------------------------------ 7ms Oct 14 16:39:01 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:01 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:01 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ" Oct 14 16:39:01 rivoplus volumio[26902]: info: ------------------------------ 879ms Oct 14 16:39:01 rivoplus volumio[26902]: info: ------------------------------ 879ms Oct 14 16:39:01 rivoplus volumio[26902]: info: Oct 14 16:39:01 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:01 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:01 rivoplus volumio[26902]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ" took 2 milliseconds Oct 14 16:39:01 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:39:01 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand play Oct 14 16:39:01 rivoplus volumio[26902]: info: Oct 14 16:39:01 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:01 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:01 rivoplus volumio[26902]: info: Oct 14 16:39:01 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:01 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:01 rivoplus volumio[26902]: info: ------------------------------ 4ms Oct 14 16:39:01 rivoplus volumio[26902]: info: sendMpdCommand play took 4 milliseconds Oct 14 16:39:01 rivoplus volumio[26902]: info: ------------------------------ 4ms Oct 14 16:39:01 rivoplus volumio[26902]: info: ------------------------------ 3ms Oct 14 16:39:02 rivoplus volumio[26902]: info: Oct 14 16:39:02 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:02 rivoplus volumio[26902]: info: Oct 14 16:39:02 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:02 rivoplus volumio[26902]: info: Oct 14 16:39:02 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand status took 87 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:02 rivoplus volumio[26902]: info: Oct 14 16:39:02 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:02 rivoplus volumio[26902]: info: Oct 14 16:39:02 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand status took 96 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand status took 95 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:02 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1494 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","trackType":"qobuz"} Oct 14 16:39:02 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:39:02 rivoplus volumio[26902]: info: ------------------------------ 105ms Oct 14 16:39:02 rivoplus volumio[26902]: info: Oct 14 16:39:02 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand status took 12 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand status took 9 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:02 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":331,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1820 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","trackType":"qobuz"} Oct 14 16:39:02 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:02 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:02 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":615,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1823 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","trackType":"qobuz"} Oct 14 16:39:02 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:02 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.504+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.505+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.506+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.507+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.508+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.508+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.513+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.514+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio[26902]: info: ------------------------------ 141ms Oct 14 16:39:02 rivoplus volumio[26902]: info: ------------------------------ 141ms Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand status took 42 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:02 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1832 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","trackType":"qobuz"} Oct 14 16:39:02 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:02 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:02 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1832 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","trackType":"qobuz"} Oct 14 16:39:02 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:02 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: ------------------------------ 101ms Oct 14 16:39:02 rivoplus volumio[26902]: info: ------------------------------ 99ms Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.560+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.560+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.560+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.561+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.561+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.562+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.562+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.563+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio[26902]: info: Signalling Playback active due to playback status change Oct 14 16:39:02 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 90 milliseconds Oct 14 16:39:02 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:02 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1832 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988740&hmac=cC_gyFNoiQDTytnaUX6GgBH75EQ","trackType":"qobuz"} Oct 14 16:39:02 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:02 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:02 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:02 rivoplus volumio[26902]: info: ------------------------------ 163ms Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.631+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=277 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.631+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.633+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=277 volume=100 Oct 14 16:39:02 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:02.634+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:02 rivoplus volumio[26902]: info: MCU Signalled Playback Active Oct 14 16:39:02 rivoplus volumio[26902]: info: MCU Signalled Sleep Mode Disabled Oct 14 16:39:02 rivoplus sudo[10432]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Oct 14 16:39:02 rivoplus sudo[10432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 16:39:02 rivoplus sudo[10432]: pam_unix(sudo:session): session closed for user root Oct 14 16:39:02 rivoplus kernel: fb: osd[0] enable: 1 (Xorg) Oct 14 16:39:02 rivoplus kernel: fb: osd[0] enable: 1 (Xorg) Oct 14 16:39:02 rivoplus sudo[10435]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Oct 14 16:39:02 rivoplus sudo[10435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 16:39:02 rivoplus sudo[10435]: pam_unix(sudo:session): session closed for user root Oct 14 16:39:03 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::ClearQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::stPlaybackTimer Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::serviceStop Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::serviceStop Oct 14 16:39:03 rivoplus volumio[26902]: info: [1791985143826] ControllerQobuz::stop Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::stop Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::clearPlayQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::addQueueItems Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::addQueueItems Oct 14 16:39:03 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/437417702 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/437417702 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.845+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.846+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPlay Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::play index 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::addQueueItems Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::addQueueItems Oct 14 16:39:03 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/440879153 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/440879153 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/444927822 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/444927822 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/437452757 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/437452757 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/446903513 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/446903513 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/429026697 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/429026697 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/448990359 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/448990359 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/439445075 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/439445075 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/442642367 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/442642367 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/443104633 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/443104633 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/436002220 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/436002220 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/431651081 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/431651081 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/417946382 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/417946382 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/444944359 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/444944359 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/438879991 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/438879991 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/418693792 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/418693792 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/426882827 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/426882827 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/412981431 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/412981431 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/416105033 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/416105033 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/421781887 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/421781887 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/452162253 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/452162253 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/414532675 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/414532675 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/442635358 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/442635358 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/450036400 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/450036400 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/435200889 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/435200889 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/441180048 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/441180048 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/447827808 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/447827808 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/418109267 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/418109267 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/448031663 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/448031663 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/445391382 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/445391382 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/450732372 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/450732372 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/445808534 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/445808534 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/438725809 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/438725809 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/419617471 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/419617471 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/444749342 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/444749342 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/429473719 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/429473719 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/423475184 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/423475184 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/414425748 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/414425748 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/433293932 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/433293932 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/434444429 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/434444429 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/408615380 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/408615380 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/395977940 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/395977940 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/392889657 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/392889657 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/403169418 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/403169418 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/401765782 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/401765782 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/408605525 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/408605525 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/358918103 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/358918103 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/407834844 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/407834844 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/397944493 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/397944493 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/404097129 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/404097129 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/388521550 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/388521550 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/406607763 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/406607763 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/400934289 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/400934289 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/398854700 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/398854700 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/409943356 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/409943356 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/412048645 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/412048645 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/393088444 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/393088444 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/404457206 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/404457206 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/404127732 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/404127732 Oct 14 16:39:03 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://song/411338004 Oct 14 16:39:03 rivoplus volumio[26902]: info: Using cached record of: qobuz://song/411338004 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::play index undefined Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::startPlaybackTimer Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: [1791985143904] ControllerQobuz::clearAddPlayTrack Oct 14 16:39:03 rivoplus volumio[26902]: info: Oct 14 16:39:03 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand stop took 115 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:03 rivoplus volumio[26902]: info: Oct 14 16:39:03 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:03 rivoplus volumio[26902]: info: Oct 14 16:39:03 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand status took 7 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand status took 9 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand status took 8 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:39:03 rivoplus volumio[26902]: info: ------------------------------ 23ms Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.968+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=4 volume=100 Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.971+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:03 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:39:03 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:03 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:03 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.989+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=4 volume=100 Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.990+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.991+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=4 volume=100 Oct 14 16:39:03 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:03.991+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:03 rivoplus volumio[26902]: info: ------------------------------ 54ms Oct 14 16:39:03 rivoplus volumio[26902]: info: ------------------------------ 53ms Oct 14 16:39:04 rivoplus volumio[26902]: info: MCU Signalled Playback Inactive Oct 14 16:39:04 rivoplus volumio[26902]: info: getStreamUrl took 149 milliseconds Oct 14 16:39:04 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:39:04 rivoplus volumio[26902]: info: sendMpdCommand stop took 1 milliseconds Oct 14 16:39:04 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand clear Oct 14 16:39:04 rivoplus volumio[26902]: info: Oct 14 16:39:04 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:04 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:04 rivoplus volumio[26902]: info: sendMpdCommand clear took 2 milliseconds Oct 14 16:39:04 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc" Oct 14 16:39:04 rivoplus volumio[26902]: info: Oct 14 16:39:04 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:04 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:04 rivoplus volumio[26902]: info: Oct 14 16:39:04 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:04 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:04 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:04 rivoplus volumio[26902]: info: ------------------------------ 5ms Oct 14 16:39:04 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:04 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:04 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc" Oct 14 16:39:04 rivoplus volumio[26902]: info: ------------------------------ 506ms Oct 14 16:39:04 rivoplus volumio[26902]: info: ------------------------------ 505ms Oct 14 16:39:04 rivoplus volumio[26902]: info: Oct 14 16:39:04 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:04 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:04 rivoplus volumio[26902]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc" took 2 milliseconds Oct 14 16:39:04 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:39:04 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand play Oct 14 16:39:04 rivoplus volumio[26902]: info: Oct 14 16:39:04 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:04 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:04 rivoplus volumio[26902]: info: Oct 14 16:39:04 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:04 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:04 rivoplus volumio[26902]: info: ------------------------------ 4ms Oct 14 16:39:04 rivoplus volumio[26902]: info: sendMpdCommand play took 4 milliseconds Oct 14 16:39:04 rivoplus volumio[26902]: info: ------------------------------ 3ms Oct 14 16:39:04 rivoplus volumio[26902]: info: ------------------------------ 3ms Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 25 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 25 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 32 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 8 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 6 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 5 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:05 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 55ms Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.121+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.122+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.123+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.124+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 83ms Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 47 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 48 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 46 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 46 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:05 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:05 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:05 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:05 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.183+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.183+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.185+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.209+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.213+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.214+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 150ms Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.218+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.219+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.219+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 132ms Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.221+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.222+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.225+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.227+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.229+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.236+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.239+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 144ms Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 144ms Oct 14 16:39:05 rivoplus volumio[26902]: info: Signalling Playback active due to playback status change Oct 14 16:39:05 rivoplus volumio[26902]: info: MCU Signalled Playback Active Oct 14 16:39:05 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::ClearQueue Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::stPlaybackTimer Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::serviceStop Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::serviceStop Oct 14 16:39:05 rivoplus volumio[26902]: info: [1791985145519] ControllerQobuz::stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::stop Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::clearPlayQueue Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::addQueueItems Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::addQueueItems Oct 14 16:39:05 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:39:05 rivoplus volumio[26902]: info: Adding Item to queue: qobuz://playlist/6826641 Oct 14 16:39:05 rivoplus volumio[26902]: info: Exploding uri qobuz://playlist/6826641 in service qobuz Oct 14 16:39:05 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.525+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.525+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand stop took 47 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: Oct 14 16:39:05 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 6 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 4 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand status took 4 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: No code Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: No code Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.602+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.603+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.603+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.604+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.604+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.605+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.605+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.605+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.605+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.605+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.606+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.606+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 62ms Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 62ms Oct 14 16:39:05 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 55 milliseconds Oct 14 16:39:05 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:05 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:05 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988743&hmac=35bWIQpHk5Z6QTU4JgqFamqCWLc","trackType":"qobuz"} Oct 14 16:39:05 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio[26902]: info: No code Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:05 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.645+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.645+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.646+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=504 volume=100 Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.646+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.647+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:05.647+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:05 rivoplus volumio[26902]: info: ------------------------------ 81ms Oct 14 16:39:05 rivoplus volumio[26902]: info: Signalling Playback active due to playback status change Oct 14 16:39:05 rivoplus volumio[26902]: info: MCU Signalled Playback Inactive Oct 14 16:39:05 rivoplus volumio[26902]: info: MCU Signalled Playback Active Oct 14 16:39:05 rivoplus volumio[26902]: info: explodeUri took 476 milliseconds Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushQueue Oct 14 16:39:06 rivoplus volumio[26902]: info: CorePlayQueue::saveQueue Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:39:06 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPlay Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::play index 0 Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::play index undefined Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:39:06 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::startPlaybackTimer Oct 14 16:39:06 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:06 rivoplus volumio[26902]: info: [1791985146028] ControllerQobuz::clearAddPlayTrack Oct 14 16:39:06 rivoplus volumio[26902]: info: getStreamUrl took 165 milliseconds Oct 14 16:39:06 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:39:06 rivoplus volumio[26902]: info: sendMpdCommand stop took 1 milliseconds Oct 14 16:39:06 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand clear Oct 14 16:39:06 rivoplus volumio[26902]: info: sendMpdCommand clear took 0 milliseconds Oct 14 16:39:06 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw" Oct 14 16:39:06 rivoplus volumio[26902]: info: Oct 14 16:39:06 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:06 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:06 rivoplus volumio[26902]: info: Oct 14 16:39:06 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:06 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:06 rivoplus volumio[26902]: info: Oct 14 16:39:06 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:06 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:06 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:06 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:06 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:39:06 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw" Oct 14 16:39:06 rivoplus volumio[26902]: info: ------------------------------ 496ms Oct 14 16:39:06 rivoplus volumio[26902]: info: ------------------------------ 495ms Oct 14 16:39:06 rivoplus volumio[26902]: info: ------------------------------ 494ms Oct 14 16:39:06 rivoplus volumio[26902]: info: Oct 14 16:39:06 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:06 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:06 rivoplus volumio[26902]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw" took 6 milliseconds Oct 14 16:39:06 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:39:06 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand play Oct 14 16:39:06 rivoplus volumio[26902]: info: Oct 14 16:39:06 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:06 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:06 rivoplus volumio[26902]: info: Oct 14 16:39:06 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:39:06 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:39:06 rivoplus volumio[26902]: info: ------------------------------ 21ms Oct 14 16:39:06 rivoplus volumio[26902]: info: sendMpdCommand play took 20 milliseconds Oct 14 16:39:06 rivoplus volumio[26902]: info: ------------------------------ 20ms Oct 14 16:39:06 rivoplus volumio[26902]: info: ------------------------------ 19ms Oct 14 16:39:07 rivoplus volumio[26902]: info: Oct 14 16:39:07 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:07 rivoplus volumio[26902]: info: Oct 14 16:39:07 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:07 rivoplus volumio[26902]: info: Oct 14 16:39:07 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand status took 15 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:07 rivoplus volumio[26902]: info: Oct 14 16:39:07 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand status took 17 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand status took 16 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:07 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","trackType":"qobuz"} Oct 14 16:39:07 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:39:07 rivoplus volumio[26902]: info: ------------------------------ 22ms Oct 14 16:39:07 rivoplus volumio[26902]: info: Oct 14 16:39:07 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:07 rivoplus volumio[26902]: info: Oct 14 16:39:07 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand status took 7 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand status took 3 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:07 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","trackType":"qobuz"} Oct 14 16:39:07 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:07 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:07 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","trackType":"qobuz"} Oct 14 16:39:07 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:07 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.233+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.233+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.234+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.235+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.235+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.237+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.237+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.236+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio[26902]: info: ------------------------------ 56ms Oct 14 16:39:07 rivoplus volumio[26902]: info: ------------------------------ 56ms Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand status took 39 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:07 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","trackType":"qobuz"} Oct 14 16:39:07 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:07 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:07 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","trackType":"qobuz"} Oct 14 16:39:07 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:07 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.267+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.268+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.269+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.271+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.271+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.271+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.271+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.273+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio[26902]: info: ------------------------------ 88ms Oct 14 16:39:07 rivoplus volumio[26902]: info: ------------------------------ 85ms Oct 14 16:39:07 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 76 milliseconds Oct 14 16:39:07 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:39:07 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:39:07 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":450,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=437417702&fmt=7&profile=raw&app_id=539451548&cid=4673107&etsp=1791988746&hmac=uZAhpEb92CHULts0ozLBanOA7Bw","trackType":"qobuz"} Oct 14 16:39:07 rivoplus volumio[26902]: verbose: CURRENT POSITION 0 Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:39:07 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:39:07 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.334+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=294 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.335+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=294 volume=100 Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.335+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:39:07.335+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:39:07 rivoplus volumio[26902]: info: ------------------------------ 134ms Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.798+03:00 level=INFO msg="player skip next request" component=server type=REQUEST_TYPE_PLAYER_SKIP_NEXT peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.803002ms timeout=10s Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioNext Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::next Oct 14 16:40:13 rivoplus volumio[26902]: info: [1791985213802] ControllerQobuz::next Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::next Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::stop Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::stPlaybackTimer Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::serviceStop Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 0 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::serviceStop Oct 14 16:40:13 rivoplus volumio[26902]: info: [1791985213817] ControllerQobuz::stop Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::stop Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.819+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.820+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/437417702 title="Portal to the Universe" Oct 14 16:40:13 rivoplus volumio[26902]: info: MCU Signalled Playback Inactive Oct 14 16:40:13 rivoplus volumio[26902]: info: Oct 14 16:40:13 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand stop took 133 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::play index undefined Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::startPlaybackTimer Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: [1791985213954] ControllerQobuz::clearAddPlayTrack Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::updateTrackBlock Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrackBlock Oct 14 16:40:13 rivoplus volumio[26902]: info: Oct 14 16:40:13 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:13 rivoplus volumio[26902]: info: Oct 14 16:40:13 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand status took 19 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand status took 15 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand status took 14 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:13 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:40:13 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:13 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:13 rivoplus volumio[26902]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.996+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=17 volume=100 Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.997+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=17 volume=100 Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.997+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:13 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:13.998+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:14 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:14.000+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_STOPPED positionMs=17 volume=100 Oct 14 16:40:14 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:14.000+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 57ms Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 52ms Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 51ms Oct 14 16:40:14 rivoplus volumio[26902]: info: getStreamUrl took 400 milliseconds Oct 14 16:40:14 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 16:40:14 rivoplus volumio[26902]: info: sendMpdCommand stop took 1 milliseconds Oct 14 16:40:14 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand clear Oct 14 16:40:14 rivoplus volumio[26902]: info: Oct 14 16:40:14 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:40:14 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:40:14 rivoplus volumio[26902]: info: sendMpdCommand clear took 2 milliseconds Oct 14 16:40:14 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs" Oct 14 16:40:14 rivoplus volumio[26902]: info: Oct 14 16:40:14 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:40:14 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:40:14 rivoplus volumio[26902]: info: Oct 14 16:40:14 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:40:14 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:40:14 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 224ms Oct 14 16:40:14 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs" Oct 14 16:40:14 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:40:14 rivoplus volumio[26902]: error: updateQueue error: null Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 225ms Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 224ms Oct 14 16:40:14 rivoplus volumio[26902]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs" took 2 milliseconds Oct 14 16:40:14 rivoplus volumio[26902]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 16:40:14 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand play Oct 14 16:40:14 rivoplus volumio[26902]: info: Oct 14 16:40:14 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:40:14 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:40:14 rivoplus volumio[26902]: info: Oct 14 16:40:14 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:40:14 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:40:14 rivoplus volumio[26902]: info: Oct 14 16:40:14 rivoplus volumio[26902]: ---------------------------- MPD announces system playlist update Oct 14 16:40:14 rivoplus volumio[26902]: info: Ignoring MPD Status Update Oct 14 16:40:14 rivoplus volumio[26902]: info: sendMpdCommand play took 6 milliseconds Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 5ms Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 3ms Oct 14 16:40:14 rivoplus volumio[26902]: info: ------------------------------ 2ms Oct 14 16:40:15 rivoplus volumio[26902]: info: Oct 14 16:40:15 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:15 rivoplus volumio[26902]: info: Oct 14 16:40:15 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:15 rivoplus volumio[26902]: info: Oct 14 16:40:15 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand status took 98 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:15 rivoplus volumio[26902]: info: Oct 14 16:40:15 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:15 rivoplus volumio[26902]: info: Oct 14 16:40:15 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand status took 98 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand status took 97 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:15 rivoplus volumio[26902]: info: Oct 14 16:40:15 rivoplus volumio[26902]: ---------------------------- MPD announces state update: player Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::getState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand status Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand status took 7 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:15 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"538 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","trackType":"qobuz"} Oct 14 16:40:15 rivoplus volumio[26902]: verbose: CURRENT POSITION 1 Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus stop Oct 14 16:40:15 rivoplus volumio[26902]: info: ------------------------------ 110ms Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand status took 8 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand status took 5 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseState Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:15 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"526 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","trackType":"qobuz"} Oct 14 16:40:15 rivoplus volumio[26902]: verbose: CURRENT POSITION 1 Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:40:15 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:15 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"513 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","trackType":"qobuz"} Oct 14 16:40:15 rivoplus volumio[26902]: verbose: CURRENT POSITION 1 Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:40:15 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:15 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"493 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","trackType":"qobuz"} Oct 14 16:40:15 rivoplus volumio[26902]: verbose: CURRENT POSITION 1 Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:40:15 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.301+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.301+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.302+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.302+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.302+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.302+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.303+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.303+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.305+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.306+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.310+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.311+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio[26902]: info: ------------------------------ 159ms Oct 14 16:40:15 rivoplus volumio[26902]: info: ------------------------------ 158ms Oct 14 16:40:15 rivoplus volumio[26902]: info: ------------------------------ 65ms Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 54 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: info: sendMpdCommand playlistinfo took 54 milliseconds Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:15 rivoplus volumio[26902]: verbose: ControllerMpd::parseTrackInfo Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:15 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"493 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","trackType":"qobuz"} Oct 14 16:40:15 rivoplus volumio[26902]: verbose: CURRENT POSITION 1 Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:40:15 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: ControllerMpd::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::servicePushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CorePlayQueue::getTrack 1 Oct 14 16:40:15 rivoplus volumio[26902]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"493 Kbps","isStreaming":false,"title":"file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=15100467&eid=440879153&fmt=6&profile=raw&app_id=539451548&cid=4673107&etsp=1791988814&hmac=VfcfzwajN_pyafeMIIZzGMubQEs","trackType":"qobuz"} Oct 14 16:40:15 rivoplus volumio[26902]: verbose: CURRENT POSITION 1 Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState stateService play Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::syncState currentStatus play Oct 14 16:40:15 rivoplus volumio[26902]: info: Received an update from plugin. extracting info from payload Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreStateMachine::pushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioPushState Oct 14 16:40:15 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.392+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.393+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.394+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.395+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.397+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.400+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.400+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:15.401+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" id=qobuz://song/440879153 title="princess of the souf" Oct 14 16:40:15 rivoplus volumio[26902]: info: ------------------------------ 145ms Oct 14 16:40:15 rivoplus volumio[26902]: info: ------------------------------ 143ms Oct 14 16:40:15 rivoplus volumio[26902]: info: Signalling Playback active due to playback status change Oct 14 16:40:15 rivoplus volumio[26902]: info: MCU Signalled Playback Active Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.246+03:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.360+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=http://pushupdates.volumio.org duration=110.253199ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.686+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=439.432786ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.689+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://www.googleapis.com duration=441.141419ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.798+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://securetoken.googleapis.com duration=550.670322ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.843+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=596.803027ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.879+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=628.823294ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.913+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://functions.volumio.cloud duration=663.495865ms Oct 14 16:40:16 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:16.917+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://functions.volumio.cloud duration=669.741809ms Oct 14 16:40:17 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:17.088+03:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=http://cddb.volumio.org duration=838.718519ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 14 16:40:17 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:17.103+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=http://plugins.volumio.org duration=855.975346ms Oct 14 16:40:17 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:17.226+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=979.741562ms Oct 14 16:40:17 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:17.291+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://database.volumio.cloud duration=1.042849135s Oct 14 16:40:17 rivoplus volumio5-onboarding[3912]: time=2026-10-14T16:40:17.734+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.116:55589,00:00:00:00:00:00%14 @ 0x17d80f0" latency=7.377587ms timeout=10s endpoint=https://google.com duration=1.487177901s Oct 14 16:40:18 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 14 16:40:18 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 14 16:40:18 rivoplus volumio[26902]: info: Discovery: Getting this device information Oct 14 16:40:18 rivoplus volumio[26902]: info: CoreCommandRouter::volumioGetState Oct 14 16:40:18 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 14 16:40:18 rivoplus volumio[26902]: verbose: New Socket.io Connection to 192.168.1.108:3000 from 192.168.1.116 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Oct 14 16:40:18 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 14 16:40:18 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 14 16:40:20 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 14 16:40:20 rivoplus volumio[26902]: info: handleBrowseUri took 574 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: Preload queue cleared Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/431767038 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/427834536 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/427834540 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/427834541 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/427834534 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/418708003 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/418708006 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/421944461 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/427834532 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/418708007 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/412657787 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/421944445 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/421944446 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/427834538 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/402051791 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/410714481 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/408770658 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/402992922 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/402992918 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/410714486 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/404455141 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/404455142 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/408770665 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/401015841 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/410714482 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/402992921 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/408770660 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/390683644 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/401015837 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/390683642 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/402992916 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/401015835 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/390683641 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/363369599 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/364701298 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/365181729 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/365181731 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/365181735 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/363369596 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/365181724 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/364412925 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/356962119 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/363369595 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/353248541 Oct 14 16:40:21 rivoplus volumio[26902]: info: Preloading song: qobuz://song/353248542 Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/431767038 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/427834536 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/427834540 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/427834541 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 203 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/427834534 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/418708003 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/418708006 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/421944461 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/427834532 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 366 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/418708007 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 294 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 451 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/412657787 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/421944445 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/421944446 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 425 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/427834538 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/402051791 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/410714481 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/408770658 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 342 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 582 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 462 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 438 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: explodeUri took 542 milliseconds Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/402992922 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:21 rivoplus volumio[26902]: info: Exploding uri qobuz://song/402992918 in service qobuz Oct 14 16:40:21 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/410714486 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 403 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 403 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 340 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/404455141 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 357 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 318 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/404455142 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 213 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 246 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/408770665 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 180 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 242 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/401015841 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/410714482 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 172 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/402992921 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 183 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/408770660 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/390683644 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 226 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 199 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/401015837 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/390683642 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 226 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 190 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/402992916 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 197 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/401015835 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 193 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/390683641 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/363369599 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 223 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/364701298 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 966 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 727 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 198 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/365181729 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 265 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/365181731 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 184 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: explodeUri took 242 milliseconds Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/365181735 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:22 rivoplus volumio[26902]: info: Exploding uri qobuz://song/363369596 in service qobuz Oct 14 16:40:22 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 185 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: Exploding uri qobuz://song/365181724 in service qobuz Oct 14 16:40:23 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 273 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: Exploding uri qobuz://song/364412925 in service qobuz Oct 14 16:40:23 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 168 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 233 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: Exploding uri qobuz://song/356962119 in service qobuz Oct 14 16:40:23 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: Exploding uri qobuz://song/363369595 in service qobuz Oct 14 16:40:23 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 170 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: Exploding uri qobuz://song/353248541 in service qobuz Oct 14 16:40:23 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 253 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 171 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: Exploding uri qobuz://song/353248542 in service qobuz Oct 14 16:40:23 rivoplus volumio[26902]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 167 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 228 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 216 milliseconds Oct 14 16:40:23 rivoplus volumio[26902]: info: explodeUri took 237 milliseconds Oct 14 16:40:49 rivoplus volumio[26902]: Searching all installed plugins Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: , search Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 14 16:40:49 rivoplus volumio[26902]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 14 16:40:49 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 14 16:40:50 rivoplus volumio[26902]: info: searchQOBUZUri took 1108 milliseconds Oct 14 16:40:50 rivoplus volumio[26902]: Searching all installed plugins Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: , search Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 14 16:40:50 rivoplus volumio[26902]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 14 16:40:50 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 14 16:40:50 rivoplus volumio[26902]: info: SHOUTCAST sorgulanırken bir hata oluştu Oct 14 16:40:50 rivoplus volumio[26902]: info: All search sources collected, pushing search results Oct 14 16:40:50 rivoplus volumio[26902]: info: searchQOBUZUri took 747 milliseconds Oct 14 16:40:51 rivoplus volumio[26902]: Searching all installed plugins Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: , search Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 14 16:40:51 rivoplus volumio[26902]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 14 16:40:51 rivoplus volumio[26902]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 14 16:40:51 rivoplus volumio[26902]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 14 16:40:51 rivoplus volumio[26902]: XMLStructuredError: Premature end of data in tag br line 187 (Line: 195, Column: 7) Oct 14 16:40:51 rivoplus volumio[26902]: at new XMLStructuredError (/volumio/node_modules/libxmljs/dist/lib/types.js:23:28) Oct 14 16:40:51 rivoplus volumio[26902]: at /volumio/node_modules/libxmljs/dist/lib/parse.js:190:23 Oct 14 16:40:51 rivoplus volumio[26902]: at Object.parseXml (/volumio/node_modules/libxmljs/dist/lib/parse.js:185:49) Oct 14 16:40:51 rivoplus volumio[26902]: at /volumio/app/plugins/music_service/webradio/index.js:962:31 Oct 14 16:40:51 rivoplus volumio[26902]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) { Oct 14 16:40:51 rivoplus volumio[26902]: domain: 1, Oct 14 16:40:51 rivoplus volumio[26902]: code: 77, Oct 14 16:40:51 rivoplus volumio[26902]: level: 3, Oct 14 16:40:51 rivoplus volumio[26902]: column: 7, Oct 14 16:40:51 rivoplus volumio[26902]: file: '', Oct 14 16:40:51 rivoplus volumio[26902]: line: 195, Oct 14 16:40:51 rivoplus volumio[26902]: str1: 'br', Oct 14 16:40:51 rivoplus volumio[26902]: str2: undefined, Oct 14 16:40:51 rivoplus volumio[26902]: str3: undefined, Oct 14 16:40:51 rivoplus volumio[26902]: int1: 187 Oct 14 16:40:51 rivoplus volumio[26902]: } Oct 14 16:40:51 rivoplus volumio[26902]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 14 16:40:51 rivoplus sudo[11147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-14 16:39' Oct 14 16:40:51 rivoplus sudo[11147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Sep 16 16:52:40 UTC 2026" VOLUMIO_VERSION="4.208" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="ba37532a86808e19439a6278b2d45f47"